[RPi3] Kodi doesn't reconnect automatically to WiFi after a blackout

Had a look at the journal now. Nothing obvious. iwd just fails telling me the key was invalid (which of course it is not as it works after the next boot). Unfortunately, only connmand is verbose, iwd not so much:

Quote

LibreELEC iwd[469]: event: connect-failed, status: 16
LibreELEC iwd[469]: event: state, old: connecting, new: disconnected
LibreELEC iwd[469]: event: state, old: disconnected, new: autoconnect_quick
LibreELEC connmand[651]: ../plugins/iwd.c:cm_network_connect_cb() /net/connman/iwd/0/3/465249545a21426f78203735323020574f_psk connect failed: net.connman.iwd.Failed
LibreELEC connmand[651]: ../src/network.c:connman_network_set_error() network 0xef27a60 error 3
LibreELEC connmand[651]: ../src/service.c:__connman_service_indicate_error() service 0xef27cb0 error 7
LibreELEC connmand[651]: ../src/service.c:set_error() service 0xef27cb0 (wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk) error 7 (invalid-key)
LibreELEC connmand[651]: Interface wlan0 [ wifi ] error "invalid-key"
LibreELEC connmand[651]: ../src/service.c:__connman_service_ipconfig_indicate_state() service 0xef27cb0 (wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk) type 1 (IPv4) old state 3 (configuration) new state 7 (failure)
LibreELEC connmand[651]: ../src/ipconfig.c:__connman_ipconfig_disable() ipconfig 0xef27ff0
LibreELEC connmand[651]: ../src/ipconfig.c:__connman_ipconfig_unref_debug() 0xef27ff0 ref 2 by ../src/ipconfig.c:1998:__connman_ipconfig_disable()
LibreELEC connmand[651]: ../src/service.c:service_indicate_state() service 0xef27cb0 (wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk) old configuration - new failure/idle => failure
LibreELEC connmand[651]: Interface wlan0 [ wifi ] state is failure
LibreELEC connmand[651]: ../plugins/vpn.c:vpn_disconnect_check()
LibreELEC connmand[651]: ../src/session.c:service_state_changed() service 0xef27cb0 (wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk) state 7
LibreELEC connmand[651]: ../src/provider.c:provider_service_changed() service 0xef27cb0 wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk state 7 index 3/-1
LibreELEC connmand[651]: ../src/notifier.c:notify_idle_state() idle 1
LibreELEC connmand[651]: ../src/manager.c:idle_state() idle 1
LibreELEC connmand[651]: ../src/agent.c:connman_agent_report_error_full() agent (nil) sender (null) context 0xef27cb0 path -
LibreELEC connmand[651]: ../src/service.c:service_save() service 0xef27cb0 (wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk) new 0
LibreELEC connmand[651]: ../src/ipconfig.c:__connman_ipconfig_save() ipconfig 0xef27ff0 identifier wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk method dhcp
LibreELEC connmand[651]: ../src/ipconfig.c:__connman_ipconfig_save() ipconfig 0xef280d0 identifier wifi_d83add53bde1_465249545a21426f78203735323020574f_managed_psk method off
LibreELEC connmand[651]: ../src/service.c:service_list_sort() from service_indicate_state()
LibreELEC connmand[651]: ../src/gateway.c:__connman_gateway_update()
LibreELEC connmand[651]: ../src/gateway.c:gateway_data_debug() from __connman_gateway_update() default_gateway (nil)
LibreELEC connmand[651]: ../src/gateway.c:__connman_gateway_update() updated4 0 updated6 0
LibreELEC connmand[651]: ipconfig state 7 ipconfig method 1
LibreELEC connmand[651]: ../src/network.c:__connman_network_disconnect() network 0xef27a60
LibreELEC connmand[651]: ../src/network.c:connman_network_set_associating() network 0xef27a60 associating 0
LibreELEC connmand[651]: ../src/network.c:set_disconnected() service 0xef27cb0 ipv4 0xef27ff0 ipv6 0xef280d0
LibreELEC connmand[651]: ../src/network.c:set_disconnected() method ipv4 4 ipv6 1
LibreELEC connmand[651]: ../src/dhcp.c:__connman_dhcp_stop() ipconfig_table 0xef10400 ipconfig 0xef27ff0
LibreELEC iwd[469]: event: state, old: autoconnect_full, new: disconnected

Display More

Of course I meant the key is NOT invalid. Unfortunately I cannot edit my post.

Edit: corrected.

The "invalid-key" error is something internal to the wireless stack and has nothing to do with "passphrase" for the network. It's root cause is still unknown but poor signal strength is a regular factor in it being seen.

Post the entire log somewhere else there's no point asking upstream devs to comment; it's the first thing they'll ask for.

Thanks. I can rule out poor signal strength as router and RPi4 are in direct vicinity of each other and also because the error is 100% reproducible and the workaround also works 100% of the time. Also both 2.4 and 5 GHz networks are affected. Once connection is established, there is no issue with it and I never had any dropouts/disconnects.

I'll post the full log but it'll take some time to redact as there's lots of sensitive information (neighboring WiFi stations in particular) contained within.

Can I somehow get the wireless stack to be more verbose in its output?

Fyi: Issue is also not resolved on the latest LE12-nightly.

Quote from treysis

Can I somehow get the wireless stack to be more verbose in its output?

Create:

[Service]
ExecStart=
ExecStart=/usr/lib/iwd -d

Quote from nvdias

I had some similar issues in the past, and just added a small script to crontab to force a connman restart when there's no connection.

Something like this:

in crontab (each 3 minute of the hour, test connection. The --reset-network parameters restarts connman if needed):

Code

03 * * * * /storage/bin/network-connection-test.sh --reset-network

the script:

Code

LOGFILE=/storage/logfiles/$(basename $0 .sh).log
ping -q -w 3 -c 1 `ip r | grep default | cut -d ' ' -f 3` 2>&1 > /dev/null
if [ $? -eq 0 ]; then
   echo $(date +"%y%m%d %H:%M:%S") " - Online"  >> $LOGFILE
       exit 0
else
   echo $(date +"%y%m%d %H:%M:%S") " - Offline" >> $LOGFILE
   if [ "$1" == "--reset-network" ]; then
       echo "                 - Reset network" >> $LOGFILE
       systemctl restart connman
   fi
   exit 1
fi

Display More

I just wanted to say a huge THANK-YOU to you for creating this solution which I believe has solved my LibreELEC WiFi connection inconsistencies.

I'm running it on x86-64 with a cheap realtek WiFi card that intermittently (3 times out of 4) will not associate to the WAP before the boot / wait time finishes, leaving me with an inaccessible Kodi.

It's not the WiFi network (Ubiquiti prosumer grade, multiple WAPs, etc) and it's probably not LibreELEC either - just the cheap WiFi card needing some time to think about things on bootup!

Once again, kudos!

Followup on the above, unfortunately the script in its current form does not achieve the desired effect. It detects the network is down but performing a restart of connman does not resolve.

At the moment I am manually toggling the "Active" setting in LibreELEC settings, which appears to completely reset the network stack and re-initialise the WiFi.

How can I perform this same action via a CLI command?

Quote from chewitt

Code

ifconfig wlan0 down && ifconfig wlan0 up

That ^ will bounce the wlan0 interface and thus force the interface to be reconfigured.

Perfect, thanks!

(ifconfig wlan0 down && ifconfig wlan0 up)&

If you need to do it over the wlan0 connection, don't forget to background the command ^ else the 'up' will fail

So, since the issue is not magically going to disappear, I eventually found the time to capture the logs of iwd.

Here is the log where the autoconnect after a powerloss fails:

And here is the log where autoconnect works after reboot/graceful shutdown:

I don't think it's only affecting a few users as mentioned in this infamous thread: invalid wifi key

I see a lot of posts about this error, also a very long github issue: https://github.com/LibreELEC/LibreELEC.tv/issues/7166

The user with the problem always believes it affects "lots of users" but the large number of reports (from a small number of vocal people who repeat post) vs number of active installs doesn't substantiate the claim, and over time with upstream changes to iwd, the number of new or continuing reports has declined. There are for sure some users still impacted, and we'd love that number to decline further, but that's in the hands of iwd developers not ours, and wpa_supplicant has other issues that were mitigated in the switch to iwd, so regardless of which one is used we have a "You can please some of the people some of the time, not all the people all of the time" situation, so we favour progress and moving forwards, and there is no interest to revert.

I counted at least 30 people, and those are just the ones that spoke up about it. I wonder if iwd devs are actually aware about the issue. Furthermore, I can only find bug reports regarding LinreELEC, but I guess that is due to the small number of distributions having made the switch to iwd. Actually, I couldn't find any other that uses iwd by default.

The iwd developers are aware of our reports, I have personally flagged it and provided information multiple times, and maintain a discussion about it with them. The root cause is not obvious to anyone, but this is not uncommon with wireless issues due to the sheer number of variables involved and difficulty in investigating the issue; it's one of the annoying ones where nobody has been able to isolate the factors required to replicate it.

NB: 30 = ~0.0001% of the userbase. Sorry that you are 1/30, but you are wildly over-imagining the problem.

Well, I believe it just hasn't been viewed isolated and is instead mixed with other unrelated WiFi issues. What is clear: THIS problem only (but always!) occurs when there was no graceful shutdown (reboot or boot after shutdown), but never occurs when the system was shutdown properly, on at least the RPi4 platform.

It most likely affects everyone. It's just that many people went for cable as a workaround (or in general) and never noticed that their WiFi isn't working.

So yes, the overall user base that insists on using WiFi might be low, but it's most likely every WiFi user out there.

I'll try a different platform than RPi4 when I find the time.

Quote from treysis

I counted at least 30 people, and those are just the ones that spoke up about it.

I'm wondering, beside that number is really small comparing to all RPi LibreElec users, how many of them doesn't using their devices, waiting for a solution, and how many switched to alternative methods (LAN cable, USB-wifi dongle with better antenna) and using it without issues.

BTW, did you tried with the same wifi source every times? Maybe it's some kind of settings or something at your router what with the iwd in the RPi lead to that "bug".