search

LibreELEC / LibreELEC.tv

Just enough OS for KODI
http://libreelec.tv
2.3k stars 1.13k forks source link

rtl8723bs: Invalid-key while connecting to wifi on LE12 #8731

Open vilhelmgray opened 8 months ago

vilhelmgray commented 8 months ago

This is a continuation of issue #7166 but for LE12.

When running LibreELEC-H6.aarch64-12.0-nightly-20240312-d108ae1-pine-h64-model-b.img: I get invalid-key message with any password I give. However, if I give a wrong password I also see a Network input/output error notification appear after, which seems to indicate that the correct passwords are actually detected as correct but the connection is failing on something else.

I think the Pine H64 Model B has a Realtek RTL8723BS, so it's possible something is messing up with that device driver, but that would be a different driver regardless from the one supporting the Amlogic Meson GXBB mentioned in issue #7166 . That seems to indicate the issue is not with the individual device drivers, but somewhere shared between the two.

chewitt commented 8 months ago

The issue resides in iwd (not driver code) and will remain until someone who experiences the problem runs iwd in debug mode to generate log output that can be shared with iwd devs as part of a bug report; the debug output should show the code path that results in the error message. So far staff are unable to reproduce the problem to do that.

vilhelmgray commented 8 months ago

I'll be happy to run iwd in debug mode to generate the log output necessary. How do I do that in LibreELEC? I noticed when I log in via SSH, I get

LibreELEC:~ # iwd
-sh: iwd: not found
chewitt commented 8 months ago

Copy /usr/lib/systemd/system/iwd.service to /storage/.config/system.d/iwd.service then edit the ExecStart command to append -E (developer mode). Then stop/disable/mask the original service and enable/start the new one so it's active. You should then be able to use iwctl to run debug wlan0 connect <bssid> to generate output. I'm not sure if the log output spews on-screen or into the journal, but it should be fairly obvious.

NB: ^ not tested, but based on some past ideas on generating it.

vilhelmgray commented 8 months ago

So before making those changes to iwd.service, I noticed the wifi services do not show up if I have the wired network plugged in; in the Kodi Network menu I see only the wired connection. Meanwhile, if I try to issue commands via SSH, I don't see wifi services available yet I do see the wifi powered:

LibreELEC:~ # connmanctl technologies
/net/connman/technology/ethernet
  Name = Wired
  Type = ethernet
  Powered = True
  Connected = True
  Tethering = False
  TetheringFreq = 2412
/net/connman/technology/wifi
  Name = WiFi
  Type = wifi
  Powered = True
  Connected = False
  Tethering = False
  TetheringFreq = 2412
LibreELEC:~ # connmanctl scan wifi
Scan completed for wifi
LibreELEC:~ # connmanctl services
*AO Wired                ethernet_020704b450e2_cable
LibreELEC:~ # ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: sit0@NONE: <NOARP> mtu 1480 qdisc noop qlen 1000
    link/sit 0.0.0.0 brd 0.0.0.0
3: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP8000> mtu 1500 qdisc mq qlen 1000
    link/ether 02:07:04:b4:50:e2 brd ff:ff:ff:ff:ff:ff
4: wlan0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc mq qlen 1000
    link/ether 48:46:c1:3a:22:ba brd ff:ff:ff:ff:ff:ff
LibreELEC:~ # iwctl station wlan0 scan
LibreELEC:~ # iwctl station wlan0 get-networks
                               Available networks                              
--------------------------------------------------------------------------------
      Network name                      Security            Signal
--------------------------------------------------------------------------------
No networks available

Here's the dmesg grepped for "wifi":

LibreELEC:~ # dmesg | grep wifi
[    0.250742] vcc-wifi-1: Bringing 700000uV into 3300000-3300000uV
[    0.251673] vcc-wifi-2: Bringing 700000uV into 3300000-3300000uV
[   13.510555] rtl8723bs: acquire FW from file:rtlwifi/rtl8723bs_nic.bin

Does LibreELEC have a way to access a terminal locally rather than over SSH? That would allow me to execute the commands without bringing up the wired connection.

heitbaum commented 8 months ago

You have run the commands correctlyiwctl station wlan0 get-networks should give you a list. You shouldn’t need to run the device in text mode to test this. It will allow Ethernet and WiFi together to test.

if you follow the Mar 29 onwards messages in the other issue. As a starter but given that your scan came up empty - the debug logs are when we need to look. We also need to ensure the device is in station mode not AP mode (please ensure tethering is off)

nuc12:~ # iwctl station list
                            Devices in Station Mode                            
--------------------------------------------------------------------------------
  Name                  State            Scanning
--------------------------------------------------------------------------------
  wlan0                 disconnected               

nuc12:~ # iwctl station wlan0 show
                                 Station: wlan0                                
--------------------------------------------------------------------------------
  Settable  Property              Value                                          
--------------------------------------------------------------------------------
            Scanning              no                                               
            State                 disconnected
vilhelmgray commented 8 months ago

Tethering is off according to the GUI and also via connmanctl technologies. The commands you mentioned come back with the same output as yours:

LibreELEC:~ # iwctl station list
                            Devices in Station Mode                            
--------------------------------------------------------------------------------
  Name                  State            Scanning
--------------------------------------------------------------------------------
  wlan0                 disconnected               

LibreELEC:~ # iwctl station wlan0 show
                                 Station: wlan0                                
--------------------------------------------------------------------------------
  Settable  Property              Value                                          
--------------------------------------------------------------------------------
            Scanning              no                                               
            State                 disconnected

I then repeated the iwd debug test as described in the previous issue:

LibreELEC:~ # systemctl stop iwd
LibreELEC:~ # STATE_DIRECTORY=/tmp/iwtest
LibreELEC:~ # export STATE_DIRECTORY
LibreELEC:~ # mkdir -p $STATE_DIRECTORY
LibreELEC:~ # /usr/lib/iwd -d
Wireless daemon version 2.16
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/main.c:main() Using configuration directory /etc/iwd
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/storage.c:storage_create_dirs() Using state directory /tmp/iwtest
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/main.c:nl80211_appeared() Found nl80211 interface
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/module.c:iwd_modules_init() 
station: Network configuration is disabled.
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wsc.c:wsc_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/knownnetworks.c:known_network_frequencies_load() No known frequency file found.
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap.c:__eap_method_enable() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-wsc.c:eap_wsc_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-md5.c:eap_md5_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-tls.c:eap_tls_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-ttls.c:eap_ttls_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-mschapv2.c:eap_mschapv2_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-sim.c:eap_sim_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_prime_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-peap.c:eap_peap_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-gtc.c:eap_gtc_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-pwd.c:eap_pwd_init() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_wiphy_dump_callback() New wiphy phy0 added (0)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_wiphy_dump_done() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_filtered_wiphy_dump_done() 
Wiphy: 0, Name: phy0
    Permanent Address: 48:46:c1:3a:22:ba
    2.4GHz Band:
        Bitrates (non-HT):
             1.0 Mbps
             2.0 Mbps
             5.5 Mbps
            11.0 Mbps
             6.0 Mbps
             9.0 Mbps
            12.0 Mbps
            18.0 Mbps
            24.0 Mbps
            36.0 Mbps
            48.0 Mbps
            54.0 Mbps
        HT Capabilities:
            HT40
            Short GI for 20Mhz
            Short GI for 40Mhz
        HT RX MCS indexes:
            0-7
            32
    Ciphers: BIP-CMAC-128 CCMP-128 TKIP
    Supported iftypes: ad-hoc station ap
    Driver Flags: DefaultInterface
Wiphy phy0 will only use the default interface
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_interface_dump_callback() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_get_interface_cb() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_interface_dump_done() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_use_default() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_create_from_genl() Created interface wlan0[4 1]
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for phy0 is 99
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_set_4addr() netdev: 4 use_4addr: 0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_initial_up_cb() Interface 4 initialized
event: state, old: disconnected, new: autoconnect_quick
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/rrm.c:rrm_add_frame_watches() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent register called
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent :1.4 path /net/connman/iwd_agent
Could not register frame watch type 00b0: -22
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_config_notify() Notification of command Set Interface(6)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 10
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_start() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 1 done
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_timeout() 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 2
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 2
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 20
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_start() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 2 done
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent register called
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent :1.17 path /agent/922
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_scan() Scan called from DBus
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 3
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 3
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_scan_triggered() station_scan_triggered: 0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_scan_triggered() Scan triggered for wlan0 subset 0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_disconnect() agent :1.17 disconnected
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_free() agent free 0x2ab5d450
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 3 done
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_scan_triggered() station_scan_triggered: 0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_scan_triggered() Scan triggered for wlan0 subset 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_start() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 4 done
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent register called
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent :1.18 path /agent/923
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_disconnect() agent :1.18 disconnected
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_free() agent free 0x2ab5d6c0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_timeout() 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 5
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 5
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 40
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_start() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 5 done
^CTerminate
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:release_agent() send Release to :1.4 /net/connman/iwd_agent
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_free() agent free 0x2ab5d4d0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_free() Freeing netdev wlan0[4]
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/device.c:device_free() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_free() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Removing scan context for wdev 1
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_context_free() sc: 0x2ab54bd0
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_unregister() agent unregister
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/module.c:iwd_modules_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap.c:__eap_method_disable() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-wsc.c:eap_wsc_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-md5.c:eap_md5_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-tls.c:eap_tls_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-ttls.c:eap_ttls_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-mschapv2.c:eap_mschapv2_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-sim.c:eap_sim_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_prime_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-peap.c:eap_peap_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-gtc.c:eap_gtc_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-pwd.c:eap_pwd_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/dpp.c:dpp_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/offchannel.c:offchannel_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wsc.c:wsc_exit() 
/build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
D-Bus disconnected, quitting...

However, in the other window I could only reach the iwctl station wlan0 get-networks step because it displays no networks.

vilhelmgray commented 8 months ago

I decided to try Armbian to verify whether there is some sort of hardware issue at play with my system. Armbian comes with wpa_supplicant by default, so I removed it and then followed the Debian NetworkManager/iwd page. I installed iwd (2.3-1+deb12u1) and ran network-manager (1.42.4-1). I could successfully scan and connect to a wifi access point via iwctl.

I also checked dmesg to verify the firmware:

 root@pineh64-b:~# dmesg | grep wifi
[   15.298131] rtl8723bs: acquire FW from file:rtlwifi/rtl8723bs_nic.bin

So it appears that the hardware using the same firmware is at least capable of connecting to the access point via iwd in Armbian. One difference however in this setup is NetworkManager (whereas we have connman in LibreELEC), so I'm not sure if that's affecting it.

heitbaum commented 8 months ago

Looking at this, your information seems to be a “hardware / driver issue” but as you proved with armbian - not a hardware issue. But given that the interaction is “none” on the scan - then points to firmware,driver….

do you have a different WiFi card to test with?

to validate this we will need to see the full kernel dmesg from both LE and armbian. What is the kernel difference, what is the driver difference, what is the firmware difference, what driver is being used on armbian, does the armbian firmware on LE fix things.

Please share the full iwd logs from both armbian and LE

There are a number of hits for issues with this WiFi card on google - e.g. https://groups.google.com/g/linux.debian.ports.arm/c/AcLn66gcf2E - but let’s not suggest this is the issue yet.

heitbaum commented 8 months ago

There are a number of reports with this device not working in the forum too. Some current.

also the output from rfkill list would be good.

the dts has all the right stuff in it - https://github.com/torvalds/linux/blob/master/arch/arm64/boot/dts/allwinner/sun50i-h6-pine-h64-model-b.dts - is this the same dts being used in armbian?

vilhelmgray commented 8 months ago

The title "rtl8723bs not getting a list of networks on LE12" isn't quite right because I can get a list of access points in LibreELEC GUI as long as I don't have the Ethernet connected; the problem in that situation is that I get the "invalid-key" error message when I try to connect to an access point.

However, it is true that I have not been able to get a list of access points when I try to scan with the Ethernet plugged in, which is what's causing difficulty in troubleshooting the "invalid-key" error via SSH over Ethernet. It's possible these are separate issues, but in theory connecting Ethernet should not affect the WiFi at all because they're separate devices on the board (and also I can connect both Ethernet and WiFi at the same time in Armbian as well).

I think it's safe to eliminate hardware and firmware as possible causes because I can connect and use the same device fine with the same firmware on Armbian. It's possible there is a difference in the dts or driver between the Armbian and LibreELEC build we could investigate. Here's the build configuration for Armbian for the Pine H64 Model B:

# Allwinner H6 quad core 1-3GB RAM SoC GBE eMMC
BOARD_NAME="Pine H64 model B"
BOARDFAMILY="sun50iw6"
BOARD_MAINTAINER=""
BOOTCONFIG="pine_h64_defconfig"
KERNEL_TARGET="legacy,current,edge"
BOOT_FDT_FILE="allwinner/sun50i-h6-pine-h64-model-b.dtb"
CRUSTCONFIG="h6_defconfig"

So it looks like the Armbian image is built with the same upstream Linux dts as in LibreELEC.

Doing a simple search for "pine-h64-model-b" on the Armbian build repository yielded no results for patches, so it doesn't look like they're modifying anything for this particular device and just using the upstream Linux driver as-is.

I'll collect logs of dmesg and rfkill list to see if we can determine what's different.

vilhelmgray commented 8 months ago

Here are the dmesg and config for both systems: dmesg_on_libreelec.txt config_on_libreelec.txt dmesg_on_armbian.txt config_on_armbian.txt

The rfkill list output is the same on both systems:

LibreELEC:~ # rfkill list
0: phy0: wlan
    Soft blocked: no
    Hard blocked: no
1: hci0: bluetooth
    Soft blocked: no
    Hard blocked: no
root@pineh64-b:~# rfkill list
0: phy0: Wireless LAN
    Soft blocked: no
    Hard blocked: no
1: hci0: Bluetooth
    Soft blocked: no
    Hard blocked: no
vilhelmgray commented 8 months ago

There does seem to be this patch to the r8723bs driver supposedly affecting "Wifi stability" by disabling power management: https://github.com/armbian/build/commit/b26ea8bfa042bb9b1a580c20f8a6a7d831eb5dca

vilhelmgray commented 8 months ago

I created an /etc/modprobe.d/r8723bs.conf with options r8723bs rtw_power_mgnt=0 rtw_enusbss=0 in it and restarted so that it would take effect. Unfortunately, it didn't seem to resolve the scan issue so that doesn't appear to be the problem.

The only other patch I found is this one that does seem to be some sort of "AP" bug fix: https://github.com/armbian/build/blob/main/patch/kernel/archive/sunxi-6.6/patches.armbian/drv-staging-rtl8723bs-AP-bugfix.patch

vilhelmgray commented 8 months ago

Sorry for the noise, the "AP bugfix" patch is no longer necessary thanks to a fix already upstream initializing the structure members to zero: https://lore.kernel.org/lkml/YL3lih8OqGOLjVBf@kroah.com/T/

vilhelmgray commented 8 months ago

I realized I could trigger the invalid-key error from the GUI, and then connect the Ethernet afterward to collect the log. Here's the output (MAXIT3HCAT is my access point):

LibreELEC:~ # journalctl -u iwd
Feb 27 17:26:07 LibreELEC systemd[1]: Starting iwd.service...
Feb 27 17:26:08 LibreELEC iwd[369]: Wireless daemon version 2.16
Feb 27 17:26:08 LibreELEC iwd[369]: station: Network configuration is disabled.
Feb 27 17:26:08 LibreELEC iwd[369]: Wiphy: 0, Name: phy0
Feb 27 17:26:08 LibreELEC iwd[369]:         Permanent Address: 00:00:00:00:00:00
Feb 27 17:26:08 LibreELEC iwd[369]:         2.4GHz Band:
Feb 27 17:26:08 LibreELEC iwd[369]:                 Bitrates (non-HT):
Feb 27 17:26:08 LibreELEC iwd[369]:                          1.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                          2.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                          5.5 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         11.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                          6.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                          9.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         12.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         18.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         24.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         36.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         48.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:                         54.0 Mbps
Feb 27 17:26:08 LibreELEC iwd[369]:         Ciphers: BIP-CMAC-128 CCMP-128 TKIP
Feb 27 17:26:08 LibreELEC iwd[369]:         Supported iftypes: ad-hoc station ap
Feb 27 17:26:08 LibreELEC iwd[369]:         Driver Flags: DefaultInterface
Feb 27 17:26:08 LibreELEC iwd[369]: Wiphy phy0 will only use the default interface
Feb 27 17:26:08 LibreELEC systemd[1]: Started iwd.service.
Feb 27 17:26:09 LibreELEC iwd[369]: event: state, old: disconnected, new: autoconnect_quick
Feb 27 17:26:09 LibreELEC iwd[369]: Could not register frame watch type 00b0: -22
Feb 27 17:27:07 LibreELEC iwd[369]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -45, load: 18/255
Feb 27 17:27:07 LibreELEC iwd[369]: event: state, old: autoconnect_full, new: connecting
Feb 27 17:27:07 LibreELEC iwd[369]: CMD_SET_CQM failed: Operation not supported
Feb 27 17:27:13 LibreELEC iwd[369]: event: connect-failed, status: 1
Feb 27 17:27:13 LibreELEC iwd[369]: event: state, old: connecting, new: disconnected
Feb 27 17:27:13 LibreELEC iwd[369]: event: state, old: disconnected, new: autoconnect_quick
Feb 27 17:27:13 LibreELEC iwd[369]: Unexpected connection related event -- is another supplicant running?
Feb 27 17:27:13 LibreELEC iwd[369]: event: state, old: autoconnect_full, new: disconnected

I want to try to start a custom systemd iwd.service with debug enabled for iwd, so I copied /usr/lib/systemd/system/iwd.service to /storage/.config/systemd/iwd-debug.service. I can stop the current iwd service, but I'm not sure how to start up this custom one instead:

LibreELEC:~ # systemctl start iwd-debug
Failed to start iwd-debug.service: Unit iwd-debug.service not found.
LibreELEC:~ # systemctl --user start iwd-debug
Failed to connect to bus: No medium found
chewitt commented 8 months ago 
systemctl stop iwd.service
systemctl disable iwd.service
systemctl mask iwd.service
systemctl enable /storage/.config/system.d/iwd-debug.service
systemctl start iwd-debug.service

do the same stop/disable/mask process to switch back to the non-debug one

heitbaum commented 8 months ago

There does seem to be this patch to the r8723bs driver supposedly affecting "Wifi stability" by disabling power management: armbian/build@b26ea8b

I’ve had to use similar when initially testing the rtw88 (but just ran the commands to disable the power down)

from the dmesg [8.915500] sunxi-mmc 4021000.mmc: data error, sending stopcommand - this looks bad, and I’m pretty sure this is the MMC that the Wireless is using.

In the gui (with no Ethernet) - are you seeing any wireless networks? If yes. When you connect the Ethernet do they go away? When you remove the Ethernet - do they come back?

do you see Bluetooth devices?

You may also find that screen in system tools may assist you when connecting / disconnecting the Ethernet. From within screen run your “favorite” tools. Ctrl-a d (detach) Ctrl-a c (create) Ctrl-a n (next) Ctrl-a Esc (scrollback) and screen -r (resume session)

vilhelmgray commented 8 months ago

There does seem to be this patch to the r8723bs driver supposedly affecting "Wifi stability" by disabling power management: armbian/build@b26ea8b

I’ve had to use similar when initially testing the rtw88 (but just ran the commands to disable the power down)

It does behave somewhat like it might be a power management issue (e.g. power draw from connected Ethernet turning off wifi device). But I would expect connmanctl technologies to report the wifi as powered off then, but it says it's on.

from the dmesg [8.915500] sunxi-mmc 4021000.mmc: data error, sending stopcommand - this looks bad, and I’m pretty sure this is the MMC that the Wireless is using.

The corresponding line in Armbian is this:

[    1.805787] sunxi-mmc 4021000.mmc: allocated mmc-pwrseq

So it looks like this should be allocated mmc-pwrseq? I'm not sure if that's important or just incidental.

In the gui (with no Ethernet) - are you seeing any wireless networks? If yes. When you connect the Ethernet do they go away? When you remove the Ethernet - do they come back?

do you see Bluetooth devices?

I typically can see wireless networks in the GUI menu if I boot without Ethernet plugged in (although I have had a couple times when I saw nothing show up); I can also detect bluetooth devices nearby. After plugging in Ethernet, the wifi and bluetooth goes blank like it's not detecting anything. After disconnecting the Ethernet cable, sometimes it's recovers and I can see the both wifi networks and bluetoth devices again, sometimes just the bluetooth doesn't work, and other times I can't recover at all. If the respective MMC is having trouble, maybe that would explain this sporadic behavior.

vilhelmgray commented 8 months ago

Something interesting happened when I followed @chewitt's commands to enable my custom iwd_debug and rebooted. I can see wifi networks in the menu now even while Ethernet is plugged in. However, I still experience the invalid-key error when I try to connect to my wifi router.

Here's the dmesg log: dmesg_with_iwd_debug.txt Here's the iwd_debug log:

LibreELEC:~ # journalctl -u iwd_debug
Mar 19 18:34:53 LibreELEC systemd[1]: Starting iwd_debug.service...
Mar 19 18:34:54 LibreELEC iwd[369]: Wireless daemon version 2.16
Mar 19 18:34:54 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/main.c:main() Using configuration directory /etc/iwd
Mar 19 18:34:54 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/storage.c:storage_create_dirs() Using state directory /var/lib/iwd
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/main.c:nl80211_appeared() Found nl80211 interface
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/module.c:iwd_modules_init()
Mar 19 18:34:55 LibreELEC iwd[369]: station: Network configuration is disabled.
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wsc.c:wsc_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/knownnetworks.c:known_network_frequencies_load() No known frequency file found.
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap.c:__eap_method_enable()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-wsc.c:eap_wsc_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-md5.c:eap_md5_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-tls.c:eap_tls_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-ttls.c:eap_ttls_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-mschapv2.c:eap_mschapv2_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-sim.c:eap_sim_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_prime_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-aka.c:eap_aka_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-peap.c:eap_peap_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-gtc.c:eap_gtc_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/eap-pwd.c:eap_pwd_init()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_wiphy_dump_callback() New wiphy phy0 added (0)
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_wiphy_dump_done()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_filtered_wiphy_dump_done()
Mar 19 18:34:55 LibreELEC iwd[369]: Wiphy: 0, Name: phy0
Mar 19 18:34:55 LibreELEC iwd[369]:         Permanent Address: 00:00:00:00:00:00
Mar 19 18:34:55 LibreELEC iwd[369]:         2.4GHz Band:
Mar 19 18:34:55 LibreELEC iwd[369]:                 Bitrates (non-HT):
Mar 19 18:34:55 LibreELEC iwd[369]:                          1.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                          2.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                          5.5 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         11.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                          6.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                          9.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         12.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         18.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         24.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         36.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         48.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:                         54.0 Mbps
Mar 19 18:34:55 LibreELEC iwd[369]:         Ciphers: BIP-CMAC-128 CCMP-128 TKIP
Mar 19 18:34:55 LibreELEC iwd[369]:         Supported iftypes: ad-hoc station ap
Mar 19 18:34:55 LibreELEC iwd[369]:         Driver Flags: DefaultInterface
Mar 19 18:34:55 LibreELEC iwd[369]: Wiphy phy0 will only use the default interface
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_interface_dump_callback()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_get_interface_cb()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_interface_dump_done()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_use_default()
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_create_from_genl() Created interface wlan0[4 1]
Mar 19 18:34:55 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for phy0 is 99
Mar 19 18:34:55 LibreELEC systemd[1]: Started iwd_debug.service.
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_set_4addr() netdev: 4 use_4addr: 0
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_initial_up_cb() Interface 4 initialized
Mar 19 18:34:56 LibreELEC iwd[369]: event: state, old: disconnected, new: autoconnect_quick
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 1
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 1
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/rrm.c:rrm_add_frame_watches()
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
Mar 19 18:34:56 LibreELEC iwd[369]: Could not register frame watch type 00b0: -22
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/manager.c:manager_config_notify() Notification of command Set Interface(6)
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 3
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent register called
Mar 19 18:34:56 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent :1.4 path /net/connman/iwd_agent
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 4
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification New Scan Results(34)
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 10
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_add_seen_bss() Processing BSS '04:42:1a:51:d9:c0' with SSID: MAXIT3HCAT, freq: 2427, rank: 442, strength: -4500, data_rate: 54.0
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_add_seen_bss() Added new Network "MAXIT3HCAT" security psk
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_start()
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_next() autoconnect: Trying SSID: MAXIT3HCAT
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_next() autoconnect: '04:42:1a:51:d9:c0' freq: 2427, rank: 442, strength: -4500
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_autoconnect_next() autoconnect: network_autoconnect: No such file or directory (-2)
Mar 19 18:34:57 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 1 done
Mar 19 18:34:59 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_link_notify() event 16 on ifindex 3
Mar 19 18:35:06 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_timeout() 1
Mar 19 18:35:06 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 2
Mar 19 18:35:06 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 2
Mar 19 18:35:07 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Trigger Scan(33)
Mar 19 18:35:07 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_request_triggered() Passive scan triggered for wdev 1
Mar 19 18:35:07 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_triggered() Periodic scan triggered for wdev 1
Mar 19 18:35:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_notify() Scan notification Scan Aborted(35)
Mar 19 18:35:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 20
Mar 19 18:35:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 2 done
Mar 19 18:35:35 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_timeout() 1
Mar 19 18:35:35 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 3
Mar 19 18:35:35 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 3
Mar 19 18:35:35 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 40
Mar 19 18:35:35 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 3 done
Mar 19 18:35:35 LibreELEC iwd[369]: Received error during CMD_TRIGGER_SCAN: Operation not permitted (1)
Mar 19 18:36:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_timeout() 1
Mar 19 18:36:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 4
Mar 19 18:36:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 4
Mar 19 18:36:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 80
Mar 19 18:36:15 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 4 done
Mar 19 18:36:15 LibreELEC iwd[369]: Received error during CMD_TRIGGER_SCAN: Operation not permitted (1)
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_connect()
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_connect_psk() ask_passphrase: true
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_request_passphrase() agent 0x18b91320 owner :1.4 path /net/connman/iwd_agent
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_send_next_request() send request to :1.4 /net/connman/iwd_agent
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_receive_reply() agent 0x18b91320 request id 18
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:passphrase_callback() result 0
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 19
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 20
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_cqm_rssi_update()
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 5
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 5
Mar 19 18:36:18 LibreELEC iwd[369]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -45, load: 21/255
Mar 19 18:36:18 LibreELEC iwd[369]: event: state, old: autoconnect_full, new: connecting
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 19 18:36:18 LibreELEC iwd[369]: CMD_SET_CQM failed: Operation not supported
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 5 done
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_connect_cb() 4, result: 2
Mar 19 18:36:18 LibreELEC iwd[369]: event: connect-failed, status: 1
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_reset_connection_state() 4
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Mar 19 18:36:18 LibreELEC iwd[369]: event: state, old: connecting, new: disconnected
Mar 19 18:36:18 LibreELEC iwd[369]: event: state, old: disconnected, new: autoconnect_quick
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 6
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 6
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_rearm() Arming periodic scan timer: 10
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 6 done
Mar 19 18:36:18 LibreELEC iwd[369]: Received error during CMD_TRIGGER_SCAN: Operation not permitted (1)
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_dbus_disconnect()
Mar 19 18:36:18 LibreELEC iwd[369]: event: state, old: autoconnect_full, new: disconnected
Mar 19 18:36:18 LibreELEC iwd[369]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
vilhelmgray commented 8 months ago

Here's my attempt to connect via iwctl debug:

[iwd]# debug wlan0 connect 04:42:1a:51:d9:c0
Type the network passphrase for MAXIT3HCAT psk.
Passphrase: ********************
Operation failed
LibreELEC:~ # journalctl -u iwd_debug
Feb 27 17:26:07 LibreELEC systemd[1]: Starting iwd_debug.service...
Feb 27 17:26:07 LibreELEC iwd[371]: Wireless daemon version 2.16
Feb 27 17:26:08 LibreELEC iwd[371]: station: Network configuration is disabled.
Feb 27 17:26:08 LibreELEC systemd[1]: Started iwd_debug.service.
Feb 27 17:26:09 LibreELEC iwd[371]: Wiphy: 0, Name: phy0
Feb 27 17:26:09 LibreELEC iwd[371]:         Permanent Address: 00:00:00:00:00:00
Feb 27 17:26:09 LibreELEC iwd[371]:         2.4GHz Band:
Feb 27 17:26:09 LibreELEC iwd[371]:                 Bitrates (non-HT):
Feb 27 17:26:09 LibreELEC iwd[371]:                          1.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                          2.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                          5.5 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         11.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                          6.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                          9.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         12.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         18.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         24.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         36.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         48.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:                         54.0 Mbps
Feb 27 17:26:09 LibreELEC iwd[371]:         Ciphers: BIP-CMAC-128 CCMP-128 TKIP
Feb 27 17:26:09 LibreELEC iwd[371]:         Supported iftypes: ad-hoc station ap
Feb 27 17:26:09 LibreELEC iwd[371]:         Driver Flags: DefaultInterface
Feb 27 17:26:09 LibreELEC iwd[371]: Wiphy phy0 will only use the default interface
Feb 27 17:26:10 LibreELEC iwd[371]: Could not register frame watch type 00b0: -22
Mar 19 19:10:31 LibreELEC iwd[371]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -45, load: 10/255
Mar 19 19:10:31 LibreELEC iwd[371]: event: state, old: disconnected, new: connecting
Mar 19 19:10:31 LibreELEC iwd[371]: CMD_SET_CQM failed: Operation not supported
Mar 19 19:10:38 LibreELEC iwd[371]: event: connect-failed, status: 1
Mar 19 19:10:38 LibreELEC iwd[371]: event: state, old: connecting, new: disconnected
Mar 19 19:10:38 LibreELEC iwd[371]: event: state, old: disconnected, new: autoconnect_quick
Mar 19 19:10:38 LibreELEC iwd[371]: Unexpected connection related event -- is another supplicant running?

I can connect to bluetooth devices just fine, so the issue appears to be isolated to just WiFi.

vilhelmgray commented 8 months ago

I wonder if this is a race condition of some kind. Executing iwd with -d or -E option allows me to see wireless networks even when I have Ethernet plugged in, so maybe those flags have just slowed down the iwd process enough to avoid the race condition yet it still fails with invalid-key when attempting to connect to a particular network.

vilhelmgray commented 8 months ago

I made an important discovery. I copied the device tree blob from Armbian via /sys/firmware/fdt and overwrote the /flash/sun50i-h6-pine-h64-model-b.dtb file in LibreELEC. After rebooting, I no longer experience the WiFi scan issues and I can see networks consistently with Ethernet using just normal iwd.

Here's the dmesg: dmesg_with_armbian_dtb.txt

So it seems to show that something different in the Armbian DTB file is what fixes this particular WiFi scan issue.

However, I do still see the invalid-key issue from before when I try to connect to a wireless network.

LibreELEC:~ # connmanctl
connmanctl> technologies
/net/connman/technology/ethernet
  Name = Wired
  Type = ethernet
  Powered = True
  Connected = True
  Tethering = False
  TetheringFreq = 2412
/net/connman/technology/wifi
  Name = WiFi
  Type = wifi
  Powered = True
  Connected = False
  Tethering = False
  TetheringFreq = 2412
connmanctl> scan wifi
Scan completed for wifi
connmanctl> services
*AO Wired                ethernet_020704b450e2_cable
    MAXIT3HCAT           wifi_4846c13a22ba_4d415849543348434154_managed_psk
connmanctl> agent on
Agent registered
connmanctl> connect wifi_4846c13a22ba_4d415849543348434154_managed_psk 
Agent RequestInput wifi_4846c13a22ba_4d415849543348434154_managed_psk
  Passphrase = [ Type=psk, Requirement=mandatory ]
  PreviousPassphrase = [ Type=psk, Requirement=informational, Value=my_secret_password_here ]
Passphrase? my_secret_password_here
Agent ReportError wifi_4846c13a22ba_4d415849543348434154_managed_psk
  invalid-key
connmanctl> Retry (yes/no)? no
Error /net/connman/service/wifi_4846c13a22ba_4d415849543348434154_managed_psk: Input/output error
LibreELEC:~ # systemctl status iwd
● iwd.service - Wireless service
     Loaded: loaded (/usr/lib/systemd/system/iwd.service; enabled; preset: disabled)
     Active: active (running) since Tue 2024-03-19 19:37:40 UTC; 13min ago
       Docs: man:iwd(8)
             man:iwd.config(5)
             man:iwd.network(5)
             man:iwd.ap(5)
   Main PID: 357 (iwd)
      Tasks: 1 (limit: 3035)
     Memory: 1.8M (peak: 2.9M)
        CPU: 813ms
     CGroup: /system.slice/iwd.service
             └─357 /usr/lib/iwd

Mar 19 19:44:53 LibreELEC iwd[357]: Unexpected connection related event -- is another supplicant running?
Mar 19 19:44:53 LibreELEC iwd[357]: event: state, old: autoconnect_full, new: disconnected
Mar 19 19:45:35 LibreELEC iwd[357]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -45, load: 24/255
Mar 19 19:45:35 LibreELEC iwd[357]: event: state, old: disconnected, new: connecting
Mar 19 19:45:35 LibreELEC iwd[357]: CMD_SET_CQM failed: Operation not supported
Mar 19 19:45:41 LibreELEC iwd[357]: event: connect-failed, status: 1
Mar 19 19:45:41 LibreELEC iwd[357]: event: state, old: connecting, new: disconnected
Mar 19 19:45:41 LibreELEC iwd[357]: event: state, old: disconnected, new: autoconnect_quick
Mar 19 19:45:41 LibreELEC iwd[357]: Unexpected connection related event -- is another supplicant running?
Mar 19 19:45:41 LibreELEC iwd[357]: event: state, old: autoconnect_full, new: disconnected
vilhelmgray commented 8 months ago

With the Armbian DTB loaded on LibreELEC and iwd -d executed, I tried the following:

LibreELEC:~ # iwctl station wlan0 scan
LibreELEC:~ # iwctl station wlan0 get-networks
                               Available networks                              
--------------------------------------------------------------------------------
      Network name                      Security            Signal
--------------------------------------------------------------------------------
      MAXIT3HCAT                        psk                 ****    
      MySpectrumWiFif0-2G               psk                 ****    
      Send-Newds                        psk                 ****    

LibreELEC:~ # iwctl station wlan0 connect MAXIT3HCAT
Type the network passphrase for MAXIT3HCAT psk.
Passphrase: ********************
Operation failed

Here's the journalctl -u iwd_debug log: journalctl_iwd_debug.txt

I think think is the relevant excerpt of the log where the password is entered and an error is returned:

Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_receive_reply() agent 0x355a1fd0 request id 40
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:passphrase_callback() result 0
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 19
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 20
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_cqm_rssi_update()
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 6
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 6
Mar 19 20:14:08 LibreELEC iwd[360]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -45, load: 21/255
Mar 19 20:14:08 LibreELEC iwd[360]: event: state, old: autoconnect_full, new: connecting
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 19 20:14:08 LibreELEC iwd[360]: CMD_SET_CQM failed: Operation not supported
Mar 19 20:14:08 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_netdev_event() Associating
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() expect_connect_failure not set, proceed
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 6 done
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_connect_cb() 4, result: 2
Mar 19 20:14:14 LibreELEC iwd[360]: event: connect-failed, status: 1
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_reset_connection_state() 4
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Mar 19 20:14:14 LibreELEC iwd[360]: event: state, old: connecting, new: disconnected
Mar 19 20:14:14 LibreELEC iwd[360]: event: state, old: disconnected, new: autoconnect_quick
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 7
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 7
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 19 20:14:14 LibreELEC iwd[360]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 19 20:14:14 LibreELEC iwd[360]: Unexpected connection related event -- is another supplicant running?
heitbaum commented 8 months ago

What are the kernel logs showing at this time? There should be some authentication messages: https://bbs.archlinux.org/viewtopic.php?id=264116

heitbaum commented 8 months ago

Can you please look at your wireless configuration.

As it looks to have WPA3 enabled. Can we please simplify the configuration - simple ssid: just lowercase text , a simple passphrase: just lowercase text. Just WPA2 and no Fast Transition enabled.

then hopefully we can get a clear run

vilhelmgray commented 8 months ago

What are the kernel logs showing at this time? There should be some authentication messages: https://bbs.archlinux.org/viewtopic.php?id=264116

I think those kernel lines are from some sort of kernel.service systemd unit that Arch Linux has. LibreELEC doesn't seem to have a corresponding unit file like that, but I reran the test anyway just in case.

Unfortunately, I don't see any authentication messages like in that link. Here's the connection attempt and failure with the full output of journalctl:

Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_receive_reply() agent 0x13697c60 request id 51
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:passphrase_callback() result 0
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 19
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 20
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_cqm_rssi_update()
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 8
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 8
Mar 21 16:42:21 LibreELEC iwd[364]: event: connect-info, ssid: MAXIT3HCAT, bss: 04:42:1a:51:d9:c0, signal: -51, load: 17/255
Mar 21 16:42:21 LibreELEC iwd[364]: event: state, old: autoconnect_full, new: connecting
Mar 21 16:42:21 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 21 16:42:21 LibreELEC iwd[364]: CMD_SET_CQM failed: Operation not supported
Mar 21 16:42:21 LibreELEC connmand[449]: ipconfig state 3 ipconfig method 1
Mar 21 16:42:22 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_netdev_event() Associating
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() expect_connect_failure not set, proceed
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 8 done
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_connect_cb() 4, result: 2
Mar 21 16:42:28 LibreELEC iwd[364]: event: connect-failed, status: 1
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_reset_connection_state() 4
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Mar 21 16:42:28 LibreELEC iwd[364]: event: state, old: connecting, new: disconnected
Mar 21 16:42:28 LibreELEC iwd[364]: event: state, old: disconnected, new: autoconnect_quick
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 9
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 9
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:42:28 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:42:28 LibreELEC iwd[364]: Unexpected connection related event -- is another supplicant running?

It looks like only extra information in that full print out is a connmand line:

Mar 21 16:42:21 LibreELEC connmand[449]: ipconfig state 3 ipconfig method 1
vilhelmgray commented 8 months ago

Can you please look at your wireless configuration.

As it looks to have WPA3 enabled. Can we please simplify the configuration - simple ssid: just lowercase text , a simple passphrase: just lowercase text. Just WPA2 and no Fast Transition enabled.

then hopefully we can get a clear run

I don't know what Fast Transition is. I decided to make this simple and use my Android phone as a hotspot for testing to eliminate any possible configuration issue with the wifi router.

On my phone, I configured the hotspot SSID as Pixel_5563 with the password simplepw set for WPA2 Personal. Here's the output from the LibreELEC:

LibreELEC:~ # iwctl station wlan0 scan
LibreELEC:~ # iwctl station wlan0 get-networks
                               Available networks                              
--------------------------------------------------------------------------------
      Network name                      Security            Signal
--------------------------------------------------------------------------------
      MAXIT3HCAT                        psk                 ****    
      mead                              psk                 ****    
      TP-LINK_6141                      psk                 ****    
      MySpectrumWiFif0-2G               psk                 ****    
      Pixel_5663                        psk                 ****    

LibreELEC:~ # iwctl station wlan0 connect Pixel_5663
Type the network passphrase for Pixel_5663 psk.
Passphrase: ********
Operation failed

Here's the relevant full journalctl log:

Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent register called
Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_register() agent :1.19 path /agent/602
Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_connect()
Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_connect_psk() ask_passphrase: true
Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_request_passphrase() agent 0x1369b3d0 owner :1.19 path /agent/602
Mar 21 16:55:36 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_send_next_request() send request to :1.19 /agent/602
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/agent.c:agent_receive_reply() agent 0x1369b3d0 request id 124
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:passphrase_callback() result 0
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 19
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/network.c:network_generate_sae_pt() Generating PT for Group 20
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_cqm_rssi_update()
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 20
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 20
Mar 21 16:55:39 LibreELEC iwd[364]: event: connect-info, ssid: Pixel_5663, bss: 12:37:7d:8d:07:c3, signal: -67, load: 127/255
Mar 21 16:55:39 LibreELEC iwd[364]: event: state, old: autoconnect_full, new: connecting
Mar 21 16:55:39 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 21 16:55:39 LibreELEC iwd[364]: CMD_SET_CQM failed: Operation not supported
Mar 21 16:55:39 LibreELEC connmand[449]: ipconfig state 3 ipconfig method 1
Mar 21 16:55:40 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_netdev_event() Associating
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() expect_connect_failure not set, proceed
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 20 done
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_connect_cb() 4, result: 2
Mar 21 16:55:46 LibreELEC iwd[364]: event: connect-failed, status: 1
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_reset_connection_state() 4
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Mar 21 16:55:46 LibreELEC iwd[364]: event: state, old: connecting, new: disconnected
Mar 21 16:55:46 LibreELEC iwd[364]: event: state, old: disconnected, new: autoconnect_quick
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 21
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 21
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:55:46 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:55:46 LibreELEC iwd[364]: Unexpected connection related event -- is another supplicant running?
vilhelmgray commented 8 months ago

I also tried connecting to a wireless network with no password earlier, and it's the same error as the other two:

Mar 21 16:42:37 LibreELEC iwd[364]: event: state, old: autoconnect_full, new: connecting
Mar 21 16:42:37 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_stop() Stopping periodic scan for wdev 1
Mar 21 16:42:37 LibreELEC iwd[364]: CMD_SET_CQM failed: Operation not supported
Mar 21 16:42:37 LibreELEC connmand[449]: ipconfig state 3 ipconfig method 1
Mar 21 16:42:37 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_netdev_event() Associating
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() expect_connect_failure not set, proceed
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_done() Work item 10 done
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_connect_cb() 4, result: 2
Mar 21 16:42:43 LibreELEC iwd[364]: event: connect-failed, status: 1
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_reset_connection_state() 4
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/station.c:station_roam_state_clear() 4
Mar 21 16:42:43 LibreELEC iwd[364]: event: state, old: connecting, new: disconnected
Mar 21 16:42:43 LibreELEC iwd[364]: event: state, old: disconnected, new: autoconnect_quick
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/scan.c:scan_periodic_start() Starting periodic scan for wdev 1
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_insert() Inserting work item 11
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/wiphy.c:wiphy_radio_work_next() Starting work item 11
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event()
Mar 21 16:42:43 LibreELEC iwd[364]: /build/build.LibreELEC-H6.aarch64-12.0-devel/build/iwd-2.16/src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
Mar 21 16:42:43 LibreELEC iwd[364]: Unexpected connection related event -- is another supplicant running?

So it doesn't look like the issue is related to the password at all.

vilhelmgray commented 8 months ago

Here's an excerpt of the full journalctl log on Armbian showing the WiFi being brought up and connecting successfully to my access point:

Mar 16 21:10:34 pineh64-b NetworkManager[848]: <info>  [1710623434.6247] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/3)
Mar 16 21:10:34 pineh64-b dbus-daemon[576]: [system] Activating via systemd: service name='net.connman.iwd' unit='iwd.service' requested by ':1.3' (uid=0 pid=848 comm="/usr/sbin/NetworkManager --no-daemon")
Mar 16 21:10:34 pineh64-b NetworkManager[848]: <info>  [1710623434.6300] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Mar 16 21:10:34 pineh64-b kernel: rtl8723bs: acquire FW from file:rtlwifi/rtl8723bs_nic.bin
Mar 16 21:10:34 pineh64-b armbian-led-state-restore.sh[1035]: warning: /sys/class/leds/input11::capslock/trigger could not be restored
Mar 16 21:10:34 pineh64-b armbian-led-state-restore.sh[1035]: warning: /sys/class/leds/input11::compose/trigger could not be restored
Mar 16 21:10:34 pineh64-b armbian-led-state-restore.sh[1035]: warning: /sys/class/leds/input11::kana/trigger could not be restored
Mar 16 21:10:34 pineh64-b armbian-led-state-restore.sh[1035]: warning: /sys/class/leds/input11::numlock/trigger could not be restored
Mar 16 21:10:34 pineh64-b armbian-led-state-restore.sh[1035]: warning: /sys/class/leds/input11::scrolllock/trigger could not be restored
Mar 16 21:10:34 pineh64-b systemd[1]: Starting iwd.service - Wireless service...
Mar 16 21:10:34 pineh64-b systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully.
Mar 16 21:10:34 pineh64-b systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP.
Mar 16 21:10:34 pineh64-b systemd[1]: Finished armbian-led-state.service - Armbian leds state.
Mar 16 21:10:34 pineh64-b kernel: NET: Registered PF_ALG protocol family
Mar 16 21:10:34 pineh64-b iwd[1046]: Wireless daemon version 2.3
Mar 16 21:10:34 pineh64-b iwd[1046]: Loaded configuration from /etc/iwd/main.conf
Mar 16 21:10:34 pineh64-b dbus-daemon[576]: [system] Successfully activated service 'net.connman.iwd'
Mar 16 21:10:34 pineh64-b systemd[1]: Started iwd.service - Wireless service.
Mar 16 21:10:34 pineh64-b systemd[1]: Startup finished in 3.617s (kernel) + 11.249s (userspace) = 14.866s.
Mar 16 21:10:34 pineh64-b iwd[1046]: station: Network configuration is disabled.
Mar 16 21:10:35 pineh64-b iwd[1046]: Wiphy: 0, Name: phy0
Mar 16 21:10:35 pineh64-b iwd[1046]:         Permanent Address: 48:46:c1:3a:22:ba
Mar 16 21:10:35 pineh64-b iwd[1046]:         2.4Ghz Band:
Mar 16 21:10:35 pineh64-b iwd[1046]:                 Bitrates (non-HT):
Mar 16 21:10:35 pineh64-b iwd[1046]:                          1.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                          2.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                          5.5 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         11.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                          6.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                          9.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         12.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         18.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         24.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         36.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         48.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                         54.0 Mbps
Mar 16 21:10:35 pineh64-b iwd[1046]:                 HT Capabilities:
Mar 16 21:10:35 pineh64-b iwd[1046]:                         HT40
Mar 16 21:10:35 pineh64-b iwd[1046]:                         Short GI for 20Mhz
Mar 16 21:10:35 pineh64-b iwd[1046]:                         Short GI for 40Mhz
Mar 16 21:10:35 pineh64-b iwd[1046]:                 HT RX MCS indexes:
Mar 16 21:10:35 pineh64-b iwd[1046]:                         0-7
Mar 16 21:10:35 pineh64-b iwd[1046]:                         32
Mar 16 21:10:35 pineh64-b iwd[1046]:         Ciphers: BIP-CMAC-128 CCMP-128 TKIP
Mar 16 21:10:35 pineh64-b iwd[1046]:         Supported iftypes: ad-hoc station ap
Mar 16 21:10:35 pineh64-b iwd[1046]: Wiphy phy0 will only use the default interface
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.8919] failed to open /run/network/ifstate
Mar 16 21:10:35 pineh64-b iwd[1046]: Unexpected connection related event -- is another supplicant running?
Mar 16 21:10:35 pineh64-b iwd[1046]: Could not register frame watch type 00b0: -22
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9234] device (wlan0): new IWD device state is disconnected
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9244] device (lo): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9255] device (lo): state change: prepare -> config (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9264] device (lo): state change: config -> ip-config (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9288] device (lo): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9308] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9363] device (lo): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9370] device (lo): state change: secondaries -> activated (reason 'none', sys-iface-state: 'external')
Mar 16 21:10:35 pineh64-b NetworkManager[848]: <info>  [1710623435.9390] device (lo): Activation: successful, device activated.
Mar 16 21:10:36 pineh64-b iwd[1046]: CMD_SET_CQM failed: Operation not supported
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.5271] device (wlan0): new IWD device state is connecting
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.5297] device (wlan0): Activation: starting connection 'MAXIT3HCAT' (1cddd9e4-cdff-410b-850b-6544bddf5a32)
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.5307] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.5318] manager: NetworkManager state is now CONNECTING
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.5327] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b iwd[1046]: hardware_rekey not supported
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.6476] device (wlan0): new IWD device state is connected
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.6481] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.6504] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.6632] dhcp4 (wlan0): state changed new lease, address=192.168.50.88
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.6646] policy: set 'MAXIT3HCAT' (wlan0) as default for IPv4 routing and DNS
Mar 16 21:10:36 pineh64-b systemd-resolved[477]: wlan0: Bus client set default route setting: yes
Mar 16 21:10:36 pineh64-b systemd-resolved[477]: wlan0: Bus client set DNS server list to: 192.168.50.1
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.7935] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.8019] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.8028] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.8045] manager: NetworkManager state is now CONNECTED_SITE
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.8068] device (wlan0): Activation: successful, device activated.
Mar 16 21:10:36 pineh64-b NetworkManager[848]: <info>  [1710623436.8086] manager: NetworkManager state is now CONNECTED_GLOBAL

Here's some connection information from the Armbian system:

root@pineh64-b:~# iwctl station wlan0 show
                                 Station: wlan0                                
--------------------------------------------------------------------------------
  Settable  Property              Value                                          
--------------------------------------------------------------------------------
            Scanning              no                                               
            State                 connected                                        
            Connected network     MAXIT3HCAT                                       
            IPv4 address          192.168.50.88                                    
            ConnectedBss          04:42:1a:51:d9:c0                                
            Frequency             2427                                             
            Security              WPA2-Personal                                    
            RSSI                  -45 dBm                                          
            TxBitrate             72200 Kbit/s
vilhelmgray commented 8 months ago

It seems a bit strange to me that swapping in the Armbian DTB file allows wireless networks to be seen in iwd. Before LibreELEC switch to iwd, I was able to connect to wireless networks via the GUI menu. I'm not sure if LibreELEC had any changes to the Pine H64 Model B device tree during that switch, but I find it odd that it would have regressed.

Another thought I've had is that perhaps the "invalid-key" issue in particular might be a regression in iwd. Armbian has an older version of iwd compared to LibreELEC so that is one difference there. It's also possible that the difference lies in the kernel Kconfig, but I'm not sure which kernel configurations options would be relevant to look at between the two.

Fludizz commented 3 months ago

This issue also seems to affect the Raspberry Pi 3 wifi capabilities. I updated my RaspberryPi (Model 3 B plus Rev 1.3) from 12.0.0 to 12.0.1 and now the WiFi on that box is also no longer working with the invalid-key message in the GUI.

After connecting a physical etheret cable I found the following in Journalctl for iwd:

Aug 27 20:28:15 chimay iwd[414]: event: connect-info, ssid: XXXXX, bss: XX:XX:XX:XX:XX:XX, signal: -38, load: 63/255
Aug 27 20:28:15 chimay iwd[414]: event: state, old: disconnected, new: connecting
Aug 27 20:28:15 chimay iwd[414]: CMD_SET_CQM failed: Operation not supported
Aug 27 20:28:15 chimay iwd[414]: event: connect-failed, status: 16

(The CMD_SET_CQM failed line can be ignored, that is present even with working WiFi on LE12.0.0) No matter what I do, I can no longer get it connected to any wifi network. GUI keeps throwing "invalid-key" error - from CLI, I get "Operation Failed".

After reverting the Pi back to 12.0.0 - the wifi immediately works again with original configuration. So seems there is something more going on here...

heitbaum commented 4 weeks ago

Is this still occurring with the latest LE13 nightlies? Are the following items (known issues) addressed: