invalid wifi key

journalctl-iwd-11.0.1chewitt-ok.log : http://ix.io/4rMO

journalctl-iwd-11.0.1chewitt-nok.log : http://ix.io/4rMP

journalctl-full-11.0.1chewitt-ok.log : http://ix.io/4rMQ

journalctl-full-11.0.1chewitt-nok.log : http://ix.io/4rMR

ok: autoconnect after boot; nok: passphrase-request

Or did you want to see the logs for LE11.0.1 official ?

Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/station.c:station_enter_state() Old State: disconnected, new state: autoconnect_quick
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 4
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/wiphy.c:wiphy_radio_work_next() Starting work item 4
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:cm_network_connect_cb() /net/connman/iwd/0/3/4c696e75782d4e6574776f726b_psk connect failed: net.connman.iwd.Failed
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
Mar 25 13:39:45 raspi connmand[661]: ipconfig state 7 ipconfig method 1
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/station.c:station_dbus_disconnect()
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/station.c:station_enter_state() Old State: autoconnect_full, new state: disconnected
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_cancel() Trying to cancel scan id 4 for wdev 1
Mar 25 13:39:45 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_cancel() Scan has been triggered, wait for it to complete
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:station_property_change() /net/connman/iwd/0/3 state disconnected
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:station_property_change() /net/connman/iwd/0/3 connected_network (null)
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:network_property_change() /net/connman/iwd/0/3/4c696e75782d4e6574776f726b_psk connected 0
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:update_network_disconnected() interface name Linux-Network
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:station_property_change() /net/connman/iwd/0/3 scanning 1
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:station_property_change() /net/connman/iwd/0/3 scanning 0
Mar 25 13:39:45 raspi connmand[661]: ../plugins/iwd.c:ordered_networks_cb()
Mar 25 13:39:49 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/scan.c:scan_notify() Scan notification New Scan Results(34)
Mar 25 13:39:49 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/wiphy.c:wiphy_radio_work_done() Work item 4 done
Mar 25 13:39:49 raspi iwd[383]: /home/chewitt/LibreELEC.rpi4/build.LibreELEC-RPi4.arm-11.0.1/build/iwd-2.3/src/netdev.c:netdev_link_notify() event 16 on ifindex 3
Mar 25 13:40:01 raspi systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Mar 25 13:40:19 raspi connmand[661]: ipconfig state 2 ipconfig method 1
Mar 25 13:40:19 raspi connmand[661]: ../plugins/iwd.c:agent_request_passphrase()

Quote from chewitt

An image for RPi4 with two additional patches from the connman list for someone to test. I have low expectations that either patch will resolve anything, but for the sake of a 30-second rebuild: https://chewitt.libreelec.tv/testing/LibreE….arm-11.0.1.tar

Are your two patches correlated with what I could study on https://lore.kernel.org/connman/202301…sts@jade.fyi/T/ ??

Quote from ajbathe

ok: autoconnect after boot; nok: passphrase-request

Not an expert on iwd debugging, but a few interesting things:

1. regulatory domain is set after the scan is triggered in the "nok" version, and before in the "ok" version. not sure if that matters.

2. the "nok" version seems to have been disconnected and reconnected, no idea why but this section is different (this appears to be the reconnect, work item 3 was the original connect attempt, then it moves on to work item 4 & 5 to retry).

wiphy.c:wiphy_radio_work_done() Work item 3 done
station.c:station_connect_cb() 3, result: 2
station.c:station_reset_connection_state() 3
station.c:station_roam_state_clear() 3
station.c:station_enter_state() Old State: connecting, new state: disconnected
station.c:station_enter_state() Old State: disconnected, new state: autoconnect_quick
scan.c:scan_periodic_start() Starting periodic scan for wdev 1
wiphy.c:wiphy_radio_work_insert() Inserting work item 4
wiphy.c:wiphy_radio_work_next() Starting work item 4
scan.c:scan_notify() Scan notification Trigger Scan(33)
scan.c:scan_request_triggered() Passive scan triggered for wdev 1
scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
station.c:station_dbus_disconnect()
station.c:station_enter_state() Old State: autoconnect_full, new state: disconnected
scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
scan.c:scan_cancel() Trying to cancel scan id 4 for wdev 1
scan.c:scan_cancel() Scan has been triggered, wait for it to complete
scan.c:scan_notify() Scan notification New Scan Results(34)
wiphy.c:wiphy_radio_work_done() Work item 4 done
netdev.c:netdev_link_notify() event 16 on ifindex 3
network.c:network_connect()
network.c:network_connect_psk() ask_passphrase: true
agent.c:agent_request_passphrase() agent 0x15765f8 owner :1.6 path /net/connman/iwd_agent
agent.c:agent_send_next_request() send request to :1.6 /net/connman/iwd_agent
agent.c:agent_receive_reply() agent 0x15765f8 request id 33
network.c:passphrase_callback() result 0
network.c:network_generate_sae_pt() Generating PT for Group 19
network.c:network_generate_sae_pt() Generating PT for Group 20
netdev.c:netdev_cqm_rssi_update()
wiphy.c:wiphy_radio_work_insert() Inserting work item 5
wiphy.c:wiphy_radio_work_next() Starting work item 5
station.c:__station_connect_network() connecting to BSS c0:25:06:ac:e3:6a
station.c:station_enter_state() Old State: disconnected, new state: connecting
station.c:station_netdev_event() Associating
netdev.c:netdev_link_notify() event 16 on ifindex 3
netdev.c:netdev_mlme_notify() MLME notification Connect(46)
netdev.c:netdev_connect_event()

This bit below seems to always happen regardless of good/bad connects, I am guessing the way connman/iwd integrate is connman has the passphrase so it probably asks iwd to scan, then tells iwd to connect, iwd says got a connect/handshake but what's the passphrase, connman sends it. So perhaps the issue is if it went through this sequence and received a disconnect and is asked again it doesn't quite know how to handle it. Line 218 is the start of the first connect attempt, then line 255 is the second one in the "nok" file.

network.c:network_connect_psk() ask_passphrase: true
agent.c:agent_request_passphrase() agent 0x15765f8 owner :1.6 path /net/connman/iwd_agent
agent.c:agent_send_next_request() send request to :1.6 /net/connman/iwd_agent
agent.c:agent_receive_reply() agent 0x15765f8 request id 33

It's possible all of the reported invalid key situations are in fact the same problem, no idea really. It might be useful to send this over to the connman/iwd mailing lists, or wait for one of the developers and see if they have any other insight.

BTW, If you have paired connman & iwd debug logs that would probably be useful to the mailing lists exhibiting good/bad at the same time.

Quote from chewitt

Based on the total number of issue reports to this forum and our IRC channel I'm calculating this problem is impacting ~0.0009% of the users running LE11 images. That level of "failure" is excellent.

It seems that it doesn't come to your mind that not everybody who uses LibreELEC knows this Forum too ?

And if you release something and you know it has a Bug, it would be nice to inform the Users about this before you relase it !

Where is the Information in the Changelog ?

LibreELEC (Nexus) 11.0 - LibreELEC

Well, I don't want argue with you, so WLAN not working in Version 11 then it's back to Version 9.2.8 for me, because "Never change a running System" (even if someone make the greatest promises about a newer version)

Quote from ajbathe

Are your two patches correlated with what I could study on

Those patches up to 1/16 appear to be already in the nightly builds. Sometime after Feb 3rd. I noticed those as well and checked what they were building.

frakkin64 the two patches I picked off the list are here: https://github.com/chewitt/connman/commits/invalid-key

Quote from frakkin64

It's possible all of the reported invalid key situations are in fact the same problem

I think you are right, it's not only RPi4 related.

Quote from frakkin64

BTW, If you have paired connman & iwd debug logs that would probably be useful to the mailing lists exhibiting good/bad at the same time.

see the full journalctl versions

http://ix.io/4rMQ & http://ix.io/4rMR - I already thought that iwd log could not be meaningful enough

and looking at https://lore.kernel.org/connman/ you will see that the devs are aware of the wifi-problematic

My attention was triggered by

Patches for the AutoConnect bug I hit in the iwd plugin 2023-01-16  7:52 UTC  (7+ messages)

chewitt

> I have low expectations that either patch will resolve anything ...

I here disagree, your version shows the right way, could you please build another for the sake version with the patches from directly above? I will test that too. When I'm hopefully not wrong, they are not integrated?!

And another small problem could be: When wired LAN comes first, WiFi won't get fired up. By observations from today with chewitts version had Wifi-only - I fear that we have to look at that too. But who uses WiFi and LAN together?! ME NOT - /joke off - Otherwise I would not have been able to do my todays contribution. Have a nice weekend.

Quote from ajbathe

see the full journalctl versions

http://ix.io/4rMQ & http://ix.io/4rMR - I already thought that iwd log could not be meaningful enough

duh, so fixated on iwd logs.

This is where things go sideways. Result 2 means NETDEV_RESULT_ASSOCIATION_FAILED, good scenario is 0. Then it sends back a failed via dbus to connman. Where to go from here, not sure, it doesn't really tell you a whole lot about what's going on, so maybe you have to debug the kernel at this point.

station.c:station_connect_cb() 3, result: 2

By the way there are reports a few years ago of iwd + brcmfmac driver problems (but I think that was in AP mode, didn't really read into it too far), that is probably one other important difference for me as I don't use built-in wifi. I use realtek 802.11ac dongles. The built-in wifi on the Pi4 is constrained to an effective ~80Mbps by the SDIO bus.

Is somebody able to crosscompile an iwd for RPi4 from the actual master of https://git.kernel.org/pub/scm/network/wireless/iwd.git ? My next idea is to replace /usr/lib/iwd with that version for LE11.0.1

Added: Not necessary anymore! I think I found the bug - compare source from LE-iwd with the master version - somewhere here sits it: diff from 2.3 and master: http://ix.io/4rR9

Because of "station.c:station_connect_cb() 3, result: 2" I would assume here is it:

diff -r iwd-2.3/src/station.c iwd-master/src/station.c
371,372c371,372
<         pos += snprintf(path + pos, sizeof(path) - pos, "%02x",
<                                 ssid[i]);
---
>         pos += snprintf(path + pos, sizeof(path) - pos, "%02hhx",
>                     ssid[i]);
2301c2301
<     if ((hs->mde[4] & 1))
---
>     if ((hs->mde[4] & 1)) {
2304,2305c2304,2311
<     else
<         ft_authenticate(netdev_get_ifindex(station->netdev), bss);
---
>         goto done;
>     }
> 
>     if (station->connected_bss->frequency == bss->frequency) {
>         ft_authenticate_onchannel(netdev_get_ifindex(station->netdev),
>                         bss);
>         goto done;
>     }
2306a2313,2315
>     ft_authenticate(netdev_get_ifindex(station->netdev), bss);
> 
> done:

What I did: I flashed the last OSMC on another SD-card, installed all packages which I needed to compile the master version I mentioned above. I put this iwd into /storage/bin and told systemd to use that version (-> drop-in with ExecStart=/storage/bin/iwd -d). I rebootet and it worked. I downgraded from chewitt to LE11.01 official. It worked! I downgraded again to LE11.0 and it works too!!

Dear LE-devs, please replace the iwd with the master-version above. And give that test-release to some many people here who have this kind of wifi-problems.

The small problem with no autoconnect when Wired-LAN is on first is - I guess IMHO - connman related because iwd only cares for Wifi, am I wrong in this thinking?

prove: http://ix.io/4rPG <- LibreELEC (official): 11.0.0

And now I can make some friends happy who need WiFi because they bought 10 meters of some Wifi cable

could this be the reason?

wireless/iwd.git - Wireless daemon for Linux

or

wireless/iwd.git - Wireless daemon for Linux

some changes since 02.02.2023 fixes my issue:

wireless/iwd.git - Wireless daemon for Linux

But this is my hottest canditate:

"ft: Introduce ft_authenticate_onchannel

Currently when we try FT-over-Air, the Authenticate frame is always sent via offchannel infrastructure We request the driver to go offchannel, then send the Authenticate frame. This works fine as long as the target AP is on a different channel. On some networks some (or all) APs might actually be located on the same channel. In this case going offchannel will result in some drivers not actually sending the Authenticate frame until after the offchannel operation completes. Work around this by introducing a new ft_authenticate variant that will not request an offchannel operation first."

wireless/iwd.git - Wireless daemon for Linux

ajbathe - ft is “fast transition” - it is used when roaming between more than one access point. It you have 2 access points - then yes, it is the likely candidate for your improved Wi-Fi authentication.

Okay, that's not my scenario, what would be your guess? But wait, I have two networks on one FritzBox 7390. This would be helpful to not compile many iwd-versions step by step upwards from version 2.3

ajbathe You can give this a shot, I do have devices on 6.1.19 with brcmfmac and haven't noticed any issues, but it may be specific to features your using that I am not, or perhaps wpa_supplicant didn't support offloading by default. It's just interesting they single out brcmfmac.

offloading [Wiki]

cat > /storage/.config/modprobe.d/brcmfmac_disable_fw_offload.conf << 'EOF'
options brcmfmac feature_disable=0x82000
EOF

Quote from frakkin64

ajbathe You can give this a shot, I do have devices on 6.1.19 with brcmfmac and haven't noticed any issues, but it may be specific to features your using that I am not, or perhaps wpa_supplicant didn't support offloading by default. It's just interesting they single out brcmfmac.

https://iwd.wiki.kernel.org/offloading

Code

cat > /storage/.config/modprobe.d/brcmfmac_disable_fw_offload.conf << 'EOF'
options brcmfmac feature_disable=0x82000
EOF

Thanx for that new info for me - I will look into that when my RPi4 machine is done with some stress test.

Good news: I haven't seen any invalid-key or operation failed messages with iwd-master, but in some rare cases - this is the bad news - autoconnect is not working 100%.

I want to know, how many of 100 boots see the WiFi network device - I do this via cronjob, waiting 60 secs, reboot and count the cases, where wlan adapter is up or not ... I would say less than 10% but I will report that here when the test done.

> or perhaps wpa_supplicant didn't support offloading by default.

wpa_supplicant is not onboard anymore, or what did you mean by mention that?

Quote from ajbathe

wpa_supplicant is not onboard anymore, or what did you mean by mention that?

No. I think the supplicant (iwd/wpa_supplicant) can request the driver to handle authentication (driver offloading) or it can handle it by receiving the raw frames. It's possible wpa_supplicant version used in 10.x didn't support driver offloading, or it had workarounds to handle driver problems, or the drivers have issues, really could be a dozen different things. Taking driver offloading out of the picture should eliminate the wifi firmware/driver code from the authentication problem, or it could still be iwd. This is just speculation, like many others I don't really have a problem, so no direct experience to speak of.

I think the only other thing to try out to eliminate the kernel/driver/firmware would be to revert to wpa_supplicant and see how that goes. You should be able to revert to wpa_supplicant by reversing this commit, but that won't be a permanent fix as they could drop the wpa_supplicant package and it may not receive any future updates since the distribution has moved on.

Edit: BTW, I doubt it's kernel or firmware, Raspberry Pi OS also pushed out the same kernel recently, and would think there would be posts on the forums. LE appears to coordinate with Raspberry Pi teams.

Here are two test images for RPi4 and Generic (GBM) that contain connman/iwd with latest patches/changes (HEAD):

https://chewitt.libreelec.tv/testing/LibreELEC-RPi4.arm-11.0.1.tar

https://chewitt.libreelec.tv/testing/LibreELEC-Generic.x86_64-11.0.1.tar

If others can confirm things are resolved we'll get the changes submitted and merged.

So, here is my final contribution of today:

I did some tests with iwd-master and LE11.0.1 official. 101 boots showed 88 good ones with autoconnection working. 13 were not-connected, I don't know why.

Who wants to see the pattern, here you go: http://ix.io/4rSS

But manually I was able to reconnect. Would guess, this looks like some timing problem, but not sure.

I created two logs again:

journalctl-iwd-master-connect.log -> http://ix.io/4rSN

journalctl-iwd-master-noconnect.log -> http://ix.io/4rSO

Because of the info from frakkin64, I also switched debugging on with "options brcmfmac debug=0x00100006 feature_disable=0x82000" for the brcmfmac kernel driver - but I guess this is not the case here. I don't use WPA3 (SAE) and only FWSUP gets disabled.

Who wants to glance at that:

brcmfmac.connected -> http://ix.io/4rSW

brcmfmac.not-connected -> http://ix.io/4rSX

Now I have to wait for some developer reactions. I am quite happy, but not perfectly The 101 cases had to be 101 good ones. Have a nice day.

Added: Ups, I saw the new test-image of chewitt (see #53 above) after writing this. My information here is not correlated. I will test that too.