AP drops STA data frames for ~130-170ms after 4-way handshake completes (ath9k_htc, mt76; not brcmfmac)

AP drops STA data frames for ~130-170ms after 4-way handshake completes (ath9k_htc, mt76; not brcmfmac)

[Thomas Hilber]

Hi,

When an AP runs on a mac80211 SoftMAC driver, data frames sent by a
freshly associated station are acknowledged at the MAC layer but never
reach the network stack for ~130-170ms after the WPA2 4-way handshake
has completed. The same station against FullMAC APs shows no such gap.

Because the frames are hardware-ACKed, the station receives no
backpressure and TCP cannot detect the loss; a dropped SYN therefore
costs a full initial RTO (~1.3s) rather than a retransmit.


Test setup
----------

One station, five APs, measured one at a time, everything else held
constant: same SSID, same WPA2-PSK passphrase, channel 11, hw_mode=g,
ieee80211n=1, 20MHz, hostapd v2.10, AP bridged to the wired LAN. The
station associates, sends one short TCP request, disconnects and deep
sleeps, repeating about once per second, so every cycle is a fresh
association. 100-140 cycles per AP. No other stations associated.

  AP  radio                    driver              kernel
  --  -----------------------  ------------------  -----------------
  1   Espressif ESP32 softAP   vendor stack        (ESP-IDF v5.5.5)
  2   MediaTek MT7986          mt76      SoftMAC   6.12.51
  3   Broadcom CYW43455        brcmfmac  FullMAC   6.18.39
  4   Atheros AR9271 (USB)     ath9k_htc SoftMAC   6.18.39
  5   Atheros AR958x           ath9k     SoftMAC   excluded, see below

Station: ESP32-C5, ESP-IDF v5.5.5.

APs 3 and 4 are the *same machine, same kernel, same hostapd binary,
same bridge, same channel*, differing only in radio and driver.


Results
-------

"attempts" is the number of TCP connect() attempts the station needed
before one succeeded; it retries every 30ms. Time is the median from
association to a completed TCP handshake.

  AP  driver              n    attempts   assoc->connected
  --  ------------------  ---  --------   ----------------
  1   vendor (FullMAC)    132     1.00           2.7 ms
  3   brcmfmac (FullMAC)  140     1.01           4.8 ms
  4   ath9k_htc (SoftMAC) 105     5.04         134   ms
  2   mt76 (SoftMAC)      118     6.19         168   ms

Association itself is 23-30ms on all four; the entire difference is in
how long the AP takes to start passing the station's data frames.


Air trace
---------

Captured with a separate monitor-mode radio (AR9271 on an unrelated
host), against AP2. Times relative to the station's Assoc Request:

    +0.0 ms   ASSOC-REQ    from STA
    +3.2 ms   ASSOC-RESP   to STA
    +7.8 ms   EAPOL        from STA      (4-way)
   +12.5 ms   EAPOL        from STA
   +15.1 ms   DATA (enc)   from STA      <- ACKed by AP
   +45.2 ms   DATA (enc)   from STA      <- ACKed
   +76 / +105 / +135 / +165 ms           <- ACKed (BlockAck)
  +178.1 ms   DATA (enc)   to STA        <- first downlink; SYN-ACK

Every one of those uplink data frames is acknowledged. None of them
appears on the AP's netdev: tcpdump on the AP interface sees no TCP SYN
until roughly the +165ms frame.

Corresponding hostapd -dd output for the same association:

  .697155  AP-STA-CONNECTED
  .697237  nl80211: Set STA flags ... flags_or=0x1
  .698663  IEEE 802.1X: authorizing port
  .698795  WPA: pairwise key handshake completed (RSN)
  .698816  EAPOL-4WAY-HS-COMPLETED

The port is authorized 0.2ms before the handshake-complete line, so
hostapd is not the one holding the frames back. Association to
EAPOL-4WAY-HS-COMPLETED is a median of 70.7ms (n=229).

There is no group-key handshake in these logs, and the behaviour is
unchanged with RADIUS accounting absent from the configuration.


Why this looks like mac80211 rather than one driver
---------------------------------------------------

Two SoftMAC drivers from unrelated vendors (ath9k_htc, mt76) both show
it; two FullMAC/firmware-offloaded stacks (brcmfmac, Espressif) both do
not. The AP3/AP4 pair isolates this to the radio and driver with
everything else identical.

That suggests the pairwise key becomes usable for RX some time after
hostapd authorizes the controlled port, rather than atomically with it.
I have not instrumented the kernel, so the split above is inference
from black-box behaviour, not from code inspection - happy to run
whatever tracing would settle it.


Anticipated objection
---------------------

The station does transmit its first data frame ~3ms after sending EAPOL
4/4, i.e. before the AP has finished installing the key. That is legal,
and more importantly the AP acknowledges those frames, so the station
has no way to learn they were discarded. FullMAC APs carry the very
same frames from the very same station without loss.


AP5 excluded
------------

The AR958x card came up in regulatory domain 00 advertising 30 dBm;
"iw reg set DE" corrected it to 20 dBm. Even then, association and the
4-way handshake succeed while no data frame ever reaches the netdev, so
that card looks miscalibrated and is not reported as a data point.


Reproducing
-----------

Any station that sends immediately on association will show it. The
metric that makes it obvious is "TCP connect attempts before success"
with a short (20-40ms) per-attempt timeout; with a normal blocking
connect it is masked as a single ~1.3s stall, which is how it went
unnoticed here for a long time.

Happy to provide pcaps, full hostapd -dd logs, or to test patches.

I am not subscribed to the list; please keep me on Cc for replies.

Thanks,
Thomas Hilber

Re: AP drops STA data frames for ~130-170ms after 4-way handshake

[Devin Wittmayer]

On Thu, 2026-08-27 at 07:44 +0200, Thomas Hilber wrote:
> That suggests the pairwise key becomes usable for RX some time after
> hostapd authorizes the controlled port, rather than atomically with it.

I think that's right, and I don't think SoftMAC is where it splits.
I ran your test on two more access points.

The first had no radio at all, just software. Median 2.8 ms over 91
associations, not one above 100. That is your FullMAC column, produced
by a SoftMAC access point.

The second was real silicon: a newer MediaTek part on its own driver,
but the same family you already reported, so corroboration rather than
a fresh witness.

  35 of 40 associations   5 to 16 ms
   5 of 40                116, 128, 138, 162, 181 ms

Your range, just not every time. About one in eight, where you were
seeing nearly all of them.

What separates the fast case from the slow ones isn't SoftMAC, it's
where decryption happens. In software the key works the instant it is
set. Everywhere else it has to be shipped out to a chip first.

The port opens on schedule. It's the key that is still in transit.

Your Atheros access point will skip hardware encryption if you ask it
to, with the nohwcrypt parameter.

If the gap goes with it, that is your answer for the price of a reload.
The MediaTek one has no such switch.

The reorder buffer is out as well. Anything dropped later, at
decryption or at the port check, has already been through it and moved
the window along, so no hole opens and the timer never starts.

Mine differs from yours in three ways: a MediaTek client instead of
your ESP32, 5 GHz wide instead of 2.4 narrow, and my clock starts at
the client's end of the handshake rather than the access point's.

Thanks for the pair that were the same box, same kernel, same hostapd,
differing only in radio and driver. That is what made this worth
chasing.

Devin

Re: AP drops STA data frames for ~130-170ms after 4-way handshake completes (ath9k_htc, mt76; not brcmfmac)

[Thomas Hilber]

On Sat, 2026-08-29 at 16:25 -0700, Devin Wittmayer wrote:
> Your Atheros access point will skip hardware encryption if you ask it
> to, with the nohwcrypt parameter.
>
> If the gap goes with it, that is your answer for the price of a reload.

It goes with it, and it takes the whole effect with it.

AP4 from my table (AR9271, ath9k_htc, kernel 6.18.39). Same station, same
hostapd, same channel, same bridge, no other station associated; the two
arms were alternated and differ only in the module parameter:

  ath9k_htc         n     connect attempts   >1 attempt   TCP connect
  --------------   ---    ----------------   ----------   -----------
  nohwcrypt=0      216          5.20            97%         134.9 ms
  nohwcrypt=1      302          1.06             3%           4.1 ms

For reference, the AP4 row of my original mail was 105 cycles at 5.04
attempts and 134 ms, taken 11 days earlier. The hardware-crypto arm above
reproduces it to within noise, which is the best evidence I have that
nothing else about the bench moved in between.

Attempt distribution, since the shape matters more than the mean:

  nohwcrypt=0    1:6   2:27  3:24  4:17  5:71  6:29  7:13  8:7  ... 16:1
  nohwcrypt=1    1:292 2:6   3:1   4:2   5:1

Under software crypto 292 of 302 associations placed their first frame
successfully. Under hardware crypto 6 of 216 did.

Two caveats, both of which cut against the result rather than for it.
Cycles where the station never got a reply at all are excluded above: 33 of
249 hardware-crypto cycles and 22 of 324 software-crypto cycles. Dropping
the hardware side's worst cycles understates the gap. And a late arm in the
session degraded for unrelated local reasons and was discarded whole rather
than pooled.

One corroboration measured at the AP, which does not depend on the station's
TCP target at all - completed four-way handshakes in fixed 120s windows,
with the station associating and deep-sleeping in a loop throughout:

  nohwcrypt=0     64, 65 associations per 120s
  nohwcrypt=1     87, 86 associations per 120s

About a third more cycles in the same wall time, which is what you would
expect if every cycle stops losing ~130ms to the dead window.

So the split in my table is not SoftMAC vs FullMAC. It is where the key
lives, exactly as you said - the same driver, on the same silicon, in the
same box, lands in either column depending on one module parameter.
Espressif and brcmfmac looked clean because the key is already in the device
by the time the port opens; ath9k_htc and mt76 look bad because the port
opens first and the key is still on its way to the chip.

That also fits your reorder-buffer point: with hardware crypto the frames
are ACKed, so they have been through the reorder window before they are
discarded, and no hole ever opens.

I have not instrumented the key-install path itself, so I still cannot say
whether the right fix is to defer authorization until the key is confirmed
installed, or to buffer rather than drop in that window. Happy to test
patches, or to run whatever tracing would distinguish those.

Thanks - that was a good call, and a cheap one.

Thomas

Re: AP drops STA data frames for ~130-170ms after 4-way handshake

[Devin Wittmayer]

On Sun, 2026-08-30 at 12:42 +0200, Thomas Hilber wrote:
> It goes with it, and it takes the whole effect with it.

Thanks for running that. Six of 216 against 292 of 302 does not need
arguing.

I have it on an MT7922 built to your AP2 spec: 27 of 95 associations hold
134 to 189 ms after the handshake, which is your 130 to 170.

They are held, not dropped. On a slow cycle my station's attempts go out
every 5 ms for 150 ms and none of them reaches the access point's
interface, until fourteen arrive within sixteen microseconds of each other
and every one is answered. Across the capture the station retransmitted
three of 110, so they were arriving all along.

A monitor radio says why. Over twenty-five associations, every request to
open a block acknowledgement session declared a starting sequence number
of zero, and zero never arrived under any of them: the first frame after
the request was one, two, three or seven. In fourteen of them the station
had already sent zero before it asked for the session.

So the reorder window opens on a sequence the station will not send. The
first slot can never be filled, everything queues behind it, and the
release timer is what eventually lets go.

Worth a look in your own captures: the starting sequence number in the
request against the sequence number of the first frame after it.

Devin

Re: AP drops STA data frames for ~130-170ms after 4-way handshake completes (ath9k_htc, mt76; not brcmfmac)

[Thomas Hilber]

On Sun, 2026-08-30 at 12:00 -0700, Devin Wittmayer wrote:
> Worth a look in your own captures: the starting sequence number in the
> request against the sequence number of the first frame after it.

Done, and it does not hold here. The window is filled correctly and my
stall happens anyway.

First, in case it is useful to anyone: I have only the one radio, and it
is the access point under test. It turns out ath9k_htc will give you a
monitor interface on the same phy while hostapd is running on it:

  iw dev wlan1 interface add mon0 type monitor

No second radio needed. (Use "iw dev <dev>", not "iw phy phyN" - rmmod
plus modprobe renumbers the phy, which cost me a run.)

Air capture and the AP's netdev, captured together, so the sequence
numbers and the stall are measured on the same associations:

                        station side          TID 0     SSN      seq==SSN
                                            sessions  declared   arrived
  nohwcrypt=0    5.36 attempts, 134.9 ms       259     0 in all   256/259
  nohwcrypt=1    1.01 attempts,   3.8 ms       348     0 in all   345/348

n=249 and n=342 cycles respectively. Of the 256 arrivals under hardware
crypto, 237 were fresh transmissions rather than retries.

So on this hardware the reorder window opens on zero, zero arrives, and
the 134.9 ms is still there. Whatever holds my frames, it is not a slot
that can never be filled.

One thing that did reproduce your signature, and then disqualified
itself. My station opens three sessions per association, TIDs 0, 5 and 7.
TID 0 carries the traffic. TID 7 declares SSN=2, the first frame to
arrive under it is seq 0, and the declared SSN never arrives in about 97%
of sessions - exactly what you describe. But it is 251/259 under hardware
crypto and 340/348 under software crypto: the same mismatch, at the same
rate, in the arm that has no stall at all. So the pattern is real here
and simply does not track the symptom.

I would not lean on my TID 7 numbers anyway. It carries 538 frames
against 3116 on TID 0, and if my station keeps one sequence counter
across TIDs rather than one per TID, a per-TID comparison there is
meaningless. TID 0 is the measurement I trust.

I also timed the first frame of each cycle from the air to the AP's
netdev: 22.2 ms median with hardware crypto against 2.4 ms with
software. The right direction, but an order of magnitude short of the
135 ms, so the frames are not simply being held for the whole window
either.

Which leaves the two of us with different mechanisms producing timings
that look alike. Mine responds to one module parameter and does not
involve a reorder hole; yours involves a reorder hole on a part that has
no such parameter to test. It may be that a missing first frame is
sufficient but not necessary, and that hardware key install can also
stall delivery some other way.

If your MT7922 will hand you a monitor interface on its own phy the way
ath9k_htc does, the cheap check on your side is whether your slow cycles
survive a session where the declared SSN *does* arrive. If they do, we
are looking at one mechanism with two symptoms; if they never do, we
have two.

Captures available if anyone wants them.

Thomas

Re: AP drops STA data frames for ~130-170ms after 4-way handshake completes (ath9k_htc, mt76; not brcmfmac)

[Devin Wittmayer]

On Mon, 2026-08-31 at 07:47 +0200, Thomas Hilber wrote:
> Done, and it does not hold here. The window is filled correctly and my
> stall happens anyway.

Welp, that kills it, and TID 0 on its own is enough. I read too much into
one capture.

Your question first, and the answer is half unhelpful. I can't check
whether my slow cycles survive a session where the SSN does arrive,
because I can't reproduce the slow cycles any more. Cleaning up the
harness took the effect with it. My traffic had been going over loopback,
and my timing metric merged the stall into the reassociation gap. Thirty
five associations on the MT7922 across both bands since, nothing in your
range at all. So treat my 27-in-95 from the 30th as unreliable until I can
produce it again.

What I can do is make your window happen deliberately.

I built stock mt76 with a module parameter that sleeps inside set_key, so
a key install takes as long as I like. Same binary both arms, the only
difference is a number I echo into sysfs. The station is on a different
driver, so the delay only hits the AP.

  keydelay_ms=0     key install   1.1 ms
  keydelay_ms=150   key install 155.3 ms

With the delay, all nine associations took 103 to 184 ms before traffic
passed again. Without it, seven of nine were back inside 78 ms.

The reason it works is that mac80211 calls the driver before the key is
reachable. In ieee80211_key_replace, enable_hw_accel runs first and the
rcu_assign_pointer that publishes the key to the RX path runs after it. So
while set_key is blocked, the AP has no key in hardware and none in
software either. It is deaf, not slow.

And yes, the MT7922 does give me a monitor interface on its own phy with
hostapd running, same as yours. So I captured air and the AP's netdev
together through an induced window. Across four windows the station put
21, 26, 25 and 25 data frames on air and the netdev saw 7, 24, 13 and 24.
In a quiet 200 ms a second later, nothing is lost at all.

Which says your 22.2 ms isn't evidence against a deaf window. Frames in
the window are dropped, not delayed, so anything timed at the netdev can
only be timing the survivors. Yours would look fast for the same reason
mine does.

So the measurement worth making is your key install.

  echo 1 > /sys/kernel/tracing/events/mac80211/drv_set_key/enable
  echo 1 > /sys/kernel/tracing/events/mac80211/drv_return_int/enable

Pair each set_key with the next return on the same pid. Near 134 ms and
it's ath9k_htc's key path. A few ms like mine and it isn't, and your
two-mechanisms reading is probably right.

Assuming CCMP, two things you can skip. The key writes take the else
branch in ath_hw_set_keycache_entry and batch into one WMI multi-write,
not six round trips. And the buffer enable and flush around them are a
paired inc/dec, so nothing sits unflushed. TKIP takes a different branch.

Thanks for the monitor-on-the-same-phy trick. That'll save people a run.

Devin