From nobody Tue Oct 21 15:24:29 2025 X-Original-To: wireless@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4crbgh03YJz6CR67 for ; Tue, 21 Oct 2025 15:24:32 +0000 (UTC) (envelope-from avg@FreeBSD.org) Received: from smtp.freebsd.org (smtp.freebsd.org [IPv6:2610:1c1:1:606c::24b:4]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "smtp.freebsd.org", Issuer "R13" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4crbgg6fTGz3Nd6; Tue, 21 Oct 2025 15:24:31 +0000 (UTC) (envelope-from avg@FreeBSD.org) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1761060271; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:autocrypt:autocrypt; bh=E9sBqnCieH0GVLSJnffPb4nbK/PGjSdswHnNMdE2M2I=; b=EVg9H7QJVohiGKjSkaVo5yPu4c2nTd8dvF8sTdWEwJsJBUCRz7sNPVTrcqmDsBmPzaalAS lspdrOawET0zamD1azvXLHCKCCpq0Kfga+nFN8U9tmcrF1z6gW2zGjsEM+yAQFibIWK4cv 2KByU7V704sihp/0qRaOKhhWyeyo8+Emmlle9TNIBosroXmD2Vw8QNudawMIBaELQekLZC ilDvQNNzbZIbyrpzMh2TB9CK83yO9J2S8q/aY+7mne1MBcaysNKLeb/9mFcKvqXLZVnKj/ 77Gz2PolJO2cl2x1bLXvpRPaun0Hu5uXj7pJsH1H6K7BeZejh4ga8IqwUfo4vQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1761060271; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:autocrypt:autocrypt; bh=E9sBqnCieH0GVLSJnffPb4nbK/PGjSdswHnNMdE2M2I=; b=vh6jnu8bubjKcRWeoFOG+9MyMCzOWW/yesGAoomxaeur/PMkBeE6JeOQ5MFQ1rtTkVBvRk vOnr1Im/NR8BikdnlYeHfrIsRVOiK2KQpAtzzW9pW8zwz5eryIZWElO/0BYtCI6UnceN6f +JskSQEzg8DRbzFI98XBcHEN0mFyFPSZ4mSFWrwYzyM03xEkzxbW0tS/6YIWgAhHEyb6A9 33u4rRiAq/Ay6EjrK0XVcEFKz9VSLB5pPbBniJf/O8dS5iGzMrFhQa1ZXKbRKPqW5t4U/c n8DibySojUprpUYIMNl0RDmXdbCDwQ5mKMWyXJNRPba+jNHv7q+PWGIfrOd3ww== ARC-Seal: i=1; s=dkim; d=freebsd.org; t=1761060271; a=rsa-sha256; cv=none; b=iu4zD21JCFls4oB1GnMjttZ9OhZ/G5uattkYbawGP/jAKwKreQ+e/FcMhYGHIuJAFw2p3r NXQ7u9N99ubtWvWpg1os1vNsnJxnWoX+SUchmhzubAXrZMoKsjs4S6NqyBB0IPV15iPeUw G3h3hefKwBey0PZnlZ8vWXYtoHZAWyihdfKfk/2+BI0GCR/+r8uITquZPyf3Z0B1p4V01N KnV0aXWK/tLtbMziYZm+UUlMXQLlx+RasbupVjN2H5ggddewMrwOraXCDRZHWmt43eFDpH yrKVSZNx1ODZH19ZSuhJqcoK/JWl5K8O4OuArHD3ALq/3rH36ymf0TDq55zweA== ARC-Authentication-Results: i=1; mx1.freebsd.org; none Received: from [192.168.0.88] (unknown [93.188.39.137]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (Client did not present a certificate) (Authenticated sender: avg/mail) by smtp.freebsd.org (Postfix) with ESMTPSA id 4crbgg2hKpzQnN; Tue, 21 Oct 2025 15:24:31 +0000 (UTC) (envelope-from avg@FreeBSD.org) Message-ID: Date: Tue, 21 Oct 2025 18:24:29 +0300 List-Id: Discussions List-Archive: https://lists.freebsd.org/archives/freebsd-wireless List-Help: List-Post: List-Subscribe: List-Unsubscribe: X-BeenThere: freebsd-wireless@freebsd.org Sender: owner-freebsd-wireless@FreeBSD.org MIME-Version: 1.0 User-Agent: Mozilla Thunderbird Subject: Re: wlan: UP but not RUNNING ? From: Andriy Gapon To: Adrian Chadd Cc: "freebsd-wireless@freebsd.org" References: <8ed936d2-242a-4dca-a38b-1117b41e87ef@FreeBSD.org> <6a2e22ae-b8f9-46de-8a0f-881d7c01ceb0@FreeBSD.org> <81321964-801f-497b-ab46-d8866401e900@FreeBSD.org> Content-Language: en-US Autocrypt: addr=avg@FreeBSD.org; keydata= xsDNBGcKrHEBDADRvwQOK0b/yo4ys5cs6bOQMhEh4xtfbaZ/CU00cpPgUip3sOZCdrtMWlRC g25z97prxE9pKueZi+HXDhIPpa9xl14ghqF4oYScuJ1i18HyiOH2y5Q3Vv/TtFiSzicd3EAu QgS3jVidpgDSPDdj2Yz3UxYpZ+PuFl6nOnvCvqOFcjUlzKCyPaiN2b86l1Nscmhnc+zQ/faB erUOEFEDQbWMA5YfXi8HrbeR16hfRfGt7E0aMDlIj9FIPIq71UWMN9CimPgs4+rbNr1MAlLa z4GxSDhVYZEY5rqtCzr+PLXboRQWnaUwXl0/biw9enf17NHdYv1SNAFTX2eC4dZ3qBVI74dS PgNprm+PMfz+6Hhs/dAv+Nan5nVhg3EFIjYTiy0MnjMSq8uI0v0ykpAGAcJJ5xl6d23aLxgN 6f0z6pJRCO0hGPgU7UzvFD0MxJxmbzqdT1R51KDan1oD41b+tjl2LMBuCDCoB0U44Pu0zLdp xMfFTxCXtwIYKIUxwd28jwMAEQEAAc0eQW5kcml5IEdhcG9uIDxhdmdARnJlZUJTRC5vcmc+ wsENBBMBCAA3FiEEmXvSmjiQFHPVOpLnzDOt5NLj67sFAmcKrHEFCQeEzgACGwMECwkIBwUV CAkKCwUWAgMBAAAKCRDMM63k0uPru5tSDACFK15LLbq89RSQ6QMnjiIm1t/wYJyumb519MHu Dhzxx1lbr8oghf0RHtF6kYRLQPaW2VdToi74pRobd3CN4bhZKDLSL6WfTn17RfavDjL6Njwp KBo30CkOeYKWq1mDmo0xEoQj8cc7ybEZnus+YScZOpj8Ti4EFwhRt6SHer7YDb161IHKL8m4 MsCxpFSGEjbKj8Iul3Ri/fTOO8w14ivcuEEQIvJt4/+4YV5Az8G23wKzL/3aJ7SOT3oYGmR9 atBTmVO3DlODjM+rZLegd8SfLSPTcBTHspWE5duemIzZbEX3BP77r3Qx4Fo5Tkit3bG1XVar yPQato+sFGFEGifdE9USBQoAoOaaeZevwAWjDU0TIuCT0CUe0sKtQuNP4LRq0n9EEHOXBu9a CfdMhFUSkAZnuE7miSVwgPvoVNJ1stA37EXLN/sVsWik7wslTQ5vF81VpdGFiwoQPOe2XEKh ogcwGSnXbwv1gD4x+Gz/7Y+kFyr1NY+4/nSaeXVcS2fOwM0EZwqscgEMAMQTe6ypAmQe/TFO HqKD2hfFKdksTptKi6uEh8xIwct8G/0FBldDWXo9eu8CGr/ZrDg0/bAwJxbaLRQCMH19Gq2Y hLvZ1QK5GQJVzZKcqfxbF2LiDUTs6WkdOBIhGpdDy7p1xFrvqCGCtNFYHuGYm067EozibBSF BWAPstKu2FQuVHZNMOfs7p3OIz3Yfqu9woXDeg3/8G2qVQJINe+8EwXKlhgh4CyDbq7nAZoA kIu1SE9z9u3WI5mcNy/0dFmVUsFxBqRC3ewbvzie8tKyZ9yFOlaZPT0Y4nRBXQTI3mLZ8zQ8 mtrWK5OOmrJ02kdeO9RBXe+OMaUUWMf92ZIoBFb4HP6N+B+4N1y1OwULousfl7JRoYxA4MRL ls7E2sSoJvrEBTJB3Pc34xu8rsJ1A5V3NgN6djX8yEZYpTRkcmrBeWy/ofDqZPVqneAx0LRm eldDS9msXDW4KXODyPZ+9unvmHAcoH0xaBYaSH44CDZDQDg4LNcmbOvuu1TEXBJhjQARAQAB wsD8BBgBCAAmFiEEmXvSmjiQFHPVOpLnzDOt5NLj67sFAmcKrHMFCQeEzgACGwwACgkQzDOt 5NLj67sUCAv5AXqgWnYN9EblapMbZjkiqL8pZQ0GNqh+Pg9FwbyULxjtRTO6rD4D0IxizByb ef+neeUNyYlagt5nfKMysEr0SU/gHKCi8vyTF/63ukMrGUNGmJJxrndl5ZYKC6j6eX7twrZF L1Uvlmn6FnQ22red5kHO93fDjG4zaDIZvHfwj7kzjZ4tpC7Byinf88s14mdZeScc0PnU2hj4 UGYju/wg2FF4YxaZYhcmdTiRYY0Wx85XSMZv19pnn78sadEuRvfRd4JTmw++j1xGXeqQGWzz /CTG5/Ex9GAkQ02hZbmi236byDXoet4G8TEyOph9QFVkV9bNd0jQZaFZPGEj4PSPUYGAF7s5 xJaNGgctC3aZ7WjEv1FBoo44XCU4xcjJ1wZQUrHxRhx6TW0Jtcl0U9qfKFW30TSPo6RyiXuj X4ltWKAtjoXB8nUmEJckaz7IRu2b4pXDeazZuz5JBygUs10yJjDxh2vFQZo0KaBAPx9MZlPn gpPTjT15L8xGftEjQXF6 In-Reply-To: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit 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 > > 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