Cannot connect to SAE protected AP with iwd 1.16 and beyond

Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 1102 bytes --]

First of all: I looked around and found no dedicated bug tracker. if this is not the place to report bugs, please excuse me, and I would be glad to be pointed in the correct direction. Thank you!

Starting with iwd 1.16 I am not able to connect to my home WLAN network. It is a WPA3 SAE protected access point running on a Netgear R7800 with OpenWRT, in case it matters. Connecting to my WPA2 PSK AP on my phone as a test works just fine.

The connection log from the client: https://pastebin.com/48umPPzh

The only but decisive log entry in the AP: https://pastebin.com/W7JsH1kY

It seems after iwd 1.16 the client tries to associate before it is correctly authenticated. Maybe a race condition, and iwd got too fast for the router?

I tried to bisect between 1.15 and 1.16 to get the commit, but I ran into problems while building (make[1]: *** No rule to make target 'ell/util.c', needed by 'ell/util.lo'.  Stop.) and I currently lack the time to troubleshoot Makefiles.

Sorry for the vague infos. If you want more logs, tell me what you need and I'll be happy to provide it! Thank you!

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 1599 bytes --]

Hi Jesus,

On 8/27/21 3:05 AM, Jesus Gonzalez wrote:
> First of all: I looked around and found no dedicated bug tracker. if this is not the place to report bugs, please excuse me, and I would be glad to be pointed in the correct direction. Thank you!

This is the correct place.

> 
> Starting with iwd 1.16 I am not able to connect to my home WLAN network. It is a WPA3 SAE protected access point running on a Netgear R7800 with OpenWRT, in case it matters. Connecting to my WPA2 PSK AP on my phone as a test works just fine.

So I take it iwd 1.15 worked fine?  We've had a similar report just a few days 
ago with Google Nest APs.  With iwd 1.16 we started negotiating a higher level 
of key encryption size by default for SAE, and that exposed some issues in the 
protocol implementation of those APs.  This might be what is happening in your 
case as well.

Can you tell us what version of hostapd your OpenWRT router is running?  hostapd 
releases are not very frequent, so a build date or commit date would be ideal, 
or any info which can help us determine that.

Also, have you tried upgrading the AP firmware?

> 
> The connection log from the client: https://pastebin.com/48umPPzh
> 
> The only but decisive log entry in the AP: https://pastebin.com/W7JsH1kY
> 
> It seems after iwd 1.16 the client tries to associate before it is correctly authenticated. Maybe a race condition, and iwd got too fast for the router?

Any chance you can run iwd standalone without NM and capture a trace for us?

See https://iwd.wiki.kernel.org/debugging

Regards,
-Denis

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 1358 bytes --]

> This is the correct place.

Thank you!

> So I take it iwd 1.15 worked fine?  We've had a similar report just a few days 
> ago with Google Nest APs.  With iwd 1.16 we started negotiating a higher level 
> of key encryption size by default for SAE, and that exposed some issues in the 
> protocol implementation of those APs.  This might be what is happening in your 
> case as well.

Indeed, 1.15 works perfectly fine. I tried running the latest git version because of the SAE patches, but it showed the same behaviour.

> Can you tell us what version of hostapd your OpenWRT router is running?  hostapd 
> releases are not very frequent, so a build date or commit date would be ideal, 
> or any info which can help us determine that.

I run a very recent build from master, the versions are:
- OpenWrt SNAPSHOT r17443-90e167abaa
- hostapd v2.10-devel (2021-05-22-b102f19b-35)

So hostapd is not the latest git head, but also not that far behind, and at a (quick and far from expert) glance most SAE activity doesn't seem related.

> Also, have you tried upgrading the AP firmware?

Already running latest firmware.

> Any chance you can run iwd standalone without NM and capture a trace for us?

Of course, here it is: https://pastebin.com/nJfpYcFA
I'll try with -d ASAP, quite busy ATM.

Thank you!

Best regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 742 bytes --]

Hello,

I got time to upgrade again and start iwd with debug output enabled, and apparently it doesn't find any suitable BSS for the AP. Looking through the code, it goes through the PSK path (correct), and doesn't mistake it for a WPA2 AP (also correct) , but it still returns an empty list as far as available and connectable BSS goes. I deleted the log by mistake, but the relevant messages, taken from the code base, were:

station.c: autoconnect: No suitable BSSes found
wiphy.c: Network is WPA3-Personal...

And that's it. The scan shows the AP perfectly fine with all the correct information (as PSK) with full signal strength, but trying to connect it returns an empty list of BSS it can actually connect to.

Regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 585 bytes --]

Hi Jesus,

> And that's it. The scan shows the AP perfectly fine with all the correct information (as PSK) with full signal strength, but trying to connect it returns an empty list of BSS it can actually connect to.

All this means is that the network is not configured.  Since you're using NM, 
the iwd backend for NM wipes all its profiles from /var/lib/iwd when NM exits. 
So iwd has nothing to connect to.

Just use 'iwctl' to connect, get a log, and 'sudo rm 
/var/lib/iwd/<yourssid>.psk' afterwards.

See: https://iwd.wiki.kernel.org/gettingstarted

Regards,
-Denis

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 280 bytes --]

Hello Denis,

this was with no NetworkManager running, and before and after a "known-networks forget" (so also entering the PSK again on "station wlan0 connect"), just in case it was what you just pointed out, which also was my first reaction to that message.

Regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Paul Menzel]

[-- Attachment #1: Type: text/plain, Size: 479 bytes --]

Dear Jesus,


Am 31.08.21 um 07:54 schrieb Jesus Gonzalez:

> this was with no NetworkManager running, and before and after a
> "known-networks forget" (so also entering the PSK again on "station
> wlan0 connect"), just in case it was what you just pointed out, which
> also was my first reaction to that message.

If you have a little time, bisecting the commit introducing the issue 
might be the quickest way to get to the bottom of this.


Kind regards,

Paul

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 710 bytes --]

Hi Jesus,

On 8/31/21 12:54 AM, Jesus Gonzalez wrote:
> Hello Denis,
> 
> this was with no NetworkManager running, and before and after a "known-networks forget" (so also entering the PSK again on "station wlan0 connect"), just in case it was what you just pointed out, which also was my first reaction to that message.

Hard to say anything definitively without seeing the logs, but I'm not sure 
anything is really wrong?

You're trying to connect to your SAE AP with iwd 1.16, right? So that is 
expected to fail: 'station wlan0 connect <foo>' will fail, and autoconnect will 
take over.  It will find nothing to connect to, as expected.

You may want to just post the log.

Regards,
-Denis

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 513 bytes --]

Hello Paul,

I took the time and found the culprit: it wasn't iwd, but ell, and this commit to be precise:

https://git.kernel.org/pub/scm/libs/ell/ell.git/commit/?id=05f4de9663950bcd4519ebec8d8c0998dc889936

After bisecting around iwd, including a breaking change within ell, and finding ell to be the problem, I started bisecting ell itself. The result is, iwd tag 1.16 (and the non-broken commits before that) all work fine with ell right before that commit.

I hope this helps.

Kind regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 443 bytes --]

Hello Denis,

the breaking commit is not in iwd, but ell. This one:

https://git.kernel.org/pub/scm/libs/ell/ell.git/commit/?id=05f4de9663950bcd4519ebec8d8c0998dc889936

I tested with no NetworkManager and no relevant .psk file in /var/lib/iwd. If you still need logs, please let me know.

I saw that you were the contributor of that patch, but stlll, if I need to file a bug somewhere else, please let me know.

Kind regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 935 bytes --]

Hi Jesus,

On 9/1/21 8:09 AM, Jesus Gonzalez wrote:
> Hello Denis,
> 
> the breaking commit is not in iwd, but ell. This one:
> 
> https://git.kernel.org/pub/scm/libs/ell/ell.git/commit/?id=05f4de9663950bcd4519ebec8d8c0998dc889936

*Jedi voice* This is not the commit you're looking for.

Seriously, yes I figured that.  This commit is the one that changes the behavior 
of which key size we choose by default when negotiating SAE.  I already 
indicated this in my very first reply on the subject :)

What we need is a log as to why the group negotiation part of the SAE handshake 
fails on your AP.  You are running a fairly recent hostapd version which 
_should_ support SAE group re-negotiation correctly.  In fact, we are running 
almost the same setup as you without any problems.

Logs from hostapd and iwd, as well as an iwmon capture would be a starting point 
for us to look into this.

Regards,
-Denis

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 582 bytes --]

Hello Denis,

thank you for your patience and humor!

Here are the relevant debug log entries from the connection attempts. The connection was already configured with iwd alone (no NetworkManager involved in the process) so I could test quickly both autoconnect and several manual attempts at connecting, so that is why you can see it autoconnecting (well, giving it a try). Connecting manually with iwctl yields the same result.

Client: https://pastebin.com/8EsRCQQQ
AP: https://pastebin.com/vJENLMdS

How do you normally get requested pcap files?

Kind regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Denis Kenzior]

[-- Attachment #1: Type: text/plain, Size: 247 bytes --]

Hi Jesus,

> thank you for your patience and humor!

no worries ;)

> 
> How do you normally get requested pcap files?
> 

Just email them to me directly as an attachment if you don't have any other 
preferred means.

Regards,
-Denis

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[James Prestwood]

[-- Attachment #1: Type: text/plain, Size: 348 bytes --]

Hi Jesus,

We think we've identified the problem which ultimately is a bug in
hostapd. Luckily it can be worked around in IWD though. Attached is a
patch which should hopefully fix your connection problem. This patch is
also on the mailing list along with some others but in your case you
should only need this single one.

Thanks,
James

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 0001-sae-don-t-send-commit-in-confirmed-state.patch --]
[-- Type: text/x-patch, Size: 1437 bytes --]

From 9964627c1e265567645cd07f5f71709073fcf2ca Mon Sep 17 00:00:00 2001
From: James Prestwood <prestwoj@gmail.com>
Date: Tue, 7 Sep 2021 14:04:07 -0700
Subject: [PATCH] sae: don't send commit in confirmed state

This works around a hostapd bug (described more in the TODO comment)
that deaths IWD if the initial commit is not acked. This behavior
has been identified in consumer access points and likely won't ever
be patched for older devices. Because of this IWD must work around
the problem which can be eliminated by not sending out this commit
message.
---
 src/sae.c | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)

diff --git a/src/sae.c b/src/sae.c
index fbd0298d..4eda9225 100644
--- a/src/sae.c
+++ b/src/sae.c
@@ -1165,7 +1165,18 @@ static int sae_verify_confirmed(struct sae_sm *sm, uint16_t trans,
 	sm->sync++;
 	sm->sc++;
 
-	sae_send_commit(sm, true);
+	/*
+	 * TODO: There is a bug in hostapd which deaths stations if a commit
+	 * is received in an Accepted SAE state. This can be triggered if the
+	 * STA's commit is not acked, which triggers a re-transmission, and
+	 * ultimated causes the AP to death IWD.
+	 *
+	 * Since this bug is present in production APs out in the wild we must
+	 * work around it by going against the spec (802.11-2020 12.4.8.6.5) and
+	 * only send a confirm here.
+	 *
+	 * sae_send_commit(sm, true);
+	 */
 
 	if (!sae_send_confirm(sm))
 		return -EPROTO;
-- 
2.31.1

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[Jesus Gonzalez]

[-- Attachment #1: Type: text/plain, Size: 531 bytes --]

Hello James,

it seems to be working, thank you! I'll keep an eye on it for the next day or so and report any error, but it was fairly obvious when it failed before in the same scenarios I just tested, so I don't expect it to fail again.

From my non-expert point of view it is weird that changing 1 encryption algorithm parameter (the curve, or its key size?) changes the behavior of the authentication/association sequence.

Sorry you had to work around this bug in hostapd! And thank you very much.

Best regards,
Jesus

Re: Cannot connect to SAE protected AP with iwd 1.16 and beyond

[James Prestwood]

[-- Attachment #1: Type: text/plain, Size: 934 bytes --]

Hi Jesus,

On Wed, 2021-09-08 at 08:41 +0000, Jesus Gonzalez wrote:
> Hello James,
> 
> it seems to be working, thank you! I'll keep an eye on it for the
> next day or so and report any error, but it was fairly obvious when
> it failed before in the same scenarios I just tested, so I don't
> expect it to fail again.
> 
> From my non-expert point of view it is weird that changing 1
> encryption algorithm parameter (the curve, or its key size?) changes
> the behavior of the authentication/association sequence.

I went into a bit more detail with Paul, but in your case I think the
status code 77 was a red herring. The actual reason your AP was denying
authentication was due to, what the AP thought was, an extra commit
message being sent which it treated as a fatal error. So by removing
this commit message in IWD we prevent that hostapd code path from being
taken in the first place.

Thanks,
James