You are not logged in.
So I've been using iwd for a while and its generally worked great. iwd version 0.16 was pushed to community a few hours ago and I updated, but I'm not able to connect at all using version 0.16.
iwd was the only package updated. It still is unable to connect after a reboot. I tried removing my /var/lib/iwd/my-wifi.psk and connecting manually with iwctl but no dice. So I downgraded to 0.14 again and it automatically reconnects just fine.
Every connection attempt from iwctl on version 0.16 reports "operation failed" and is accompanied by the following lines in the journal:
v0.16-1
Apr 04 16:13:30 rxps kernel: wlp2s0: authenticate with a4:56:cc:05:d7:8e
Apr 04 16:13:30 rxps kernel: wlp2s0: send auth to a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:13:30 rxps kernel: wlp2s0: authenticated
Apr 04 16:13:30 rxps kernel: wlp2s0: associate with a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:13:30 rxps kernel: wlp2s0: RX AssocResp from a4:56:cc:05:d7:8e (capab=0x1511 status=0 aid=9)
Apr 04 16:13:30 rxps kernel: wlp2s0: associated
Apr 04 16:13:30 rxps kernel: wlp2s0: deauthenticating from a4:56:cc:05:d7:8e by local choice (Reason: 1=UNSPECIFIED)
UNSPECIFIED is not partiularly helpful...
for reference on 0.14 I see
v0.14-1
Apr 04 16:15:02 rxps kernel: wlp2s0: authenticate with a4:56:cc:05:d7:8e
Apr 04 16:15:02 rxps kernel: wlp2s0: send auth to a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:15:02 rxps kernel: wlp2s0: authenticated
Apr 04 16:15:02 rxps kernel: wlp2s0: associate with a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:15:02 rxps kernel: wlp2s0: RX AssocResp from a4:56:cc:05:d7:8e (capab=0x1511 status=0 aid=8)
Apr 04 16:15:02 rxps kernel: wlp2s0: associated
Apr 04 16:15:02 rxps systemd-networkd[317]: wlp2s0: Gained carrier
...
And systemd-networkd does its thing.
I tried modifying 'ExecStart=/usr/lib/iwd/iwd' in the iwd.service file to include '-d' for debugging and connecting again, but I don't see anything interesting
v0.16-1 debug
Apr 04 16:33:03 rxps iwd[4633]: src/station.c:station_autoconnect_next() Considering autoconnecting to BSS 'a4:56:cc:05:d7:8e' with SSID: house3-5, freq: 5180, rank: 9126, strength: -5400
Apr 04 16:33:03 rxps iwd[4633]: src/station.c:station_enter_state() Old State: autoconnect_quick, new state: connecting
Apr 04 16:33:03 rxps iwd[4633]: src/scan.c:scan_periodic_stop() Stopping periodic scan for ifindex: 2
Apr 04 16:33:03 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 19
Apr 04 16:33:03 rxps iwd[4633]: src/station.c:station_netdev_event() Associating
Apr 04 16:33:03 rxps kernel: wlp2s0: send auth to a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:33:03 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 37
Apr 04 16:33:03 rxps iwd[4633]: src/netdev.c:netdev_authenticate_event()
Apr 04 16:33:03 rxps kernel: wlp2s0: authenticated
Apr 04 16:33:03 rxps kernel: wlp2s0: associate with a4:56:cc:05:d7:8e (try 1/3)
Apr 04 16:33:04 rxps kernel: wlp2s0: RX AssocResp from a4:56:cc:05:d7:8e (capab=0x1511 status=0 aid=8)
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 38
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_associate_event()
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 46
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_connect_event()
Apr 04 16:33:04 rxps kernel: wlp2s0: associated
Apr 04 16:33:04 rxps kernel: wlp2s0: deauthenticating from a4:56:cc:05:d7:8e by local choice (Reason: 1=UNSPECIFIED)
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 64
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 20
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 39
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_deauthenticate_event()
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_mlme_notify() MLME notification 48
Apr 04 16:33:04 rxps iwd[4633]: src/netdev.c:netdev_disconnect_event()
Apr 04 16:33:04 rxps iwd[4633]: src/station.c:station_connect_cb() 2, result: 2
Apr 04 16:33:04 rxps iwd[4633]: src/station.c:station_disassociated() 2
Apr 04 16:33:04 rxps iwd[4633]: src/station.c:station_enter_state() Old State: connecting, new state: disconnected
iwd doesn't come with a man page so I'm not sure where to go from here. Any ideas?
Last edited by Brocellous (2019-04-09 23:00:05)
Offline
Yes I am seeing exact same issue.
With iwd 0.16, it authenticates and then de-authenticates with reason as local choice!
Anyone knows what is local choice.
My log and @Brocellous logs are more or less same except that codes (capab, aid) are different.
Apr 05 08:43:25 amish kernel: wlan0: authenticate with 80:37:73:ff:cc:11
Apr 05 08:43:25 amish kernel: wlan0: send auth to 80:37:73:ff:cc:11 (try 1/3)
Apr 05 08:43:25 amish kernel: wlan0: authenticated
Apr 05 08:43:25 amish kernel: wlan0: associate with 80:37:73:ff:cc:11 (try 1/3)
Apr 05 08:43:25 amish kernel: wlan0: RX AssocResp from 80:37:73:ff:cc:11 (capab=0x411 status=0 aid=1)
Apr 05 08:43:25 amish kernel: wlan0: associated
Apr 05 08:43:25 amish kernel: wlan0: deauthenticating from 80:37:73:ff:cc:11 by local choice (Reason: 1=UNSPECIFIED)
Downgrade to 0.14 works fine.
Update:
Looking at commit logs - I tried disabling most options in /etc/iwd/main.conf (https://git.kernel.org/pub/scm/network/ … /main.conf) that were introduced after 0.14. But it didnt work.
There were many changes to iwd.service file. So I even used iwd.service from 0.14 in 0.16 - but still authenticates and de-authenticates.
Overall - whatever I tried, failed. So looks like some upstream code change is breaking my connection.
Last edited by amish (2019-04-05 08:13:10)
Offline
Well glad to know I'm not alone. For completeness sake I'll mention I also thought to try the 0.14 service file with the 0.16 daemon and saw no change. I wonder what could be causing this.
Offline
EDIT: I'm a moron. You can disregard this post, and I still don't know whats wrong.
OK so I've made some more attempts to fix this and I've got good and bad news.
The good news is its fixed, the bad news is I don't know why.
I'm not the most experienced C programmer, but I thought I'd give this a shot anyway. I couldn't think of how to attach gdb to iwd before it tries to connect so I just peppered the file I thought was responsible with warning level logging messages. After I built and installed, I had version 0.16 working like a charm with no changes to anything but logging! I thought for sure its just from building from source so I tried again with the original source files. Same error. So I add the logging messages back in one at a time and in fact there is one log message that appears to fix iwd for me! Worst of all, its never even logged!
Here is my 'patch' and procedure in detail:
abort.patch (only 1 line added !!)
--- /home/ronan/work/extra/tar-iwd/src/netdev.c 2019-04-03 10:59:41.000000000 -0700
+++ src/iwd-0.16/src/netdev.c 2019-04-05 15:32:28.144151979 -0700
@@ -2379,6 +2379,7 @@
l_debug("");
if (netdev->aborting)
+ l_warn("aborting");
return;
if (!l_genl_attr_init(&attr, msg)) {
building the patched iwd
$ asp export iwd
$ cd iwd
$ makepkg --verifysource
$ patch src/iwd-0.16/src/netdev.c abort.patch
$ makepkg -ei
And here is 0.16 working just fine after the 'patch'
$ systemctl status iwd.service
● iwd.service - Wireless service
Loaded: loaded (/usr/lib/systemd/system/iwd.service; enabled; vendor preset: disabled)
Active: active (running) since Fri 2019-04-05 15:18:12 PDT; 23min ago
Main PID: 25839 (iwd)
Tasks: 1 (limit: 4915)
Memory: 924.0K
CGroup: /system.slice/iwd.service
└─25839 /usr/lib/iwd/iwd
Apr 05 15:18:12 rxps systemd[1]: Starting Wireless service...
Apr 05 15:18:12 rxps iwd[25839]: Wireless daemon version 0.16
Apr 05 15:18:12 rxps iwd[25839]: Skipping optional configuration file /etc/iwd/main.conf
Apr 05 15:18:12 rxps systemd[1]: Started Wireless service.
Apr 05 15:18:12 rxps iwd[25839]: Wiphy: 0, Name: phy0
Apr 05 15:18:12 rxps iwd[25839]: Bands: 2.4 GHz 5 GHz
Apr 05 15:18:12 rxps iwd[25839]: Ciphers: CCMP TKIP BIP
Apr 05 15:18:12 rxps iwd[25839]: Supported iftypes: ad-hoc station ap
Apr 05 15:18:12 rxps iwd[25839]: No ControlPortOverNL80211 setting, defaulting to True
...and in the journal
Apr 05 15:18:29 rxps kernel: wlp2s0: authenticate with a4:56:cc:05:d7:8e
Apr 05 15:18:29 rxps kernel: wlp2s0: send auth to a4:56:cc:05:d7:8e (try 1/3)
Apr 05 15:18:29 rxps kernel: wlp2s0: authenticated
Apr 05 15:18:29 rxps kernel: wlp2s0: associate with a4:56:cc:05:d7:8e (try 1/3)
Apr 05 15:18:29 rxps kernel: wlp2s0: RX AssocResp from a4:56:cc:05:d7:8e (capab=0x1511 status=0 aid=8)
Apr 05 15:18:29 rxps kernel: wlp2s0: associated
Apr 05 15:18:30 rxps systemd-networkd[319]: wlp2s0: Gained carrier
...
The new log message never appears in my journal, but from my observation other warning level logs do. I assume its because that conditional block is never entered but then why would this fix it?
anyway because now I think it might be relevant, here is some more info
$ uname -a
Linux rxps 5.0.6-arch1-1-ARCH #1 SMP PREEMPT Wed Apr 3 09:35:20 UTC 2019 x86_64 GNU/Linux
$ sudo lspci -v | sed -n '/Network/,/^$/ p'
02:00.0 Network controller: Intel Corporation Wireless 8265 / 8275 (rev 78)
Subsystem: Intel Corporation Dual Band Wireless-AC 8265
Flags: bus master, fast devsel, latency 0, IRQ 139
Memory at edc00000 (64-bit, non-prefetchable) [size=8K]
Capabilities: [c8] Power Management version 3
Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
Capabilities: [40] Express Endpoint, MSI 00
Capabilities: [100] Advanced Error Reporting
Capabilities: [140] Device Serial Number cc-2f-71-ff-ff-cd-ca-94
Capabilities: [14c] Latency Tolerance Reporting
Capabilities: [154] L1 PM Substates
Kernel driver in use: iwlwifi
Kernel modules: iwlwifi
Does anyone else care to try this hack? Does it work for you? Any idea what could be happening? Creating a proper fix for this is obviously above my head. Does anyone know where I can, or if I should, report my findings to a developer? I'm not very experienced with this stuff...
Last edited by Brocellous (2019-04-05 23:18:04)
Offline
if (netdev->aborting)
+ l_warn("aborting");
return;
I think the issue is that with the addition of the l_warn the return is no longer guarded by the if i.e.
if (netdev->aborting)
l_warn("aborting");
return;
or
if (netdev->aborting)
l_warn("aborting");
else
return;
Last edited by loqs (2019-04-05 23:10:30)
Offline
@loqs You are absolutely right, thanks. Strange that it works at all in that case. Thanks for your help. I think I'll just stick to 0.14 for now.
Offline
Offline
@loqs You are absolutely right, thanks. Strange that it works at all in that case. Thanks for your help. I think I'll just stick to 0.14 for now.
Your code worked because for our kind of router / AP, function netdev_associate_event() was supposed to just "return" without proceeding.
As @loqs pointed out, what actually happened is your code inadvertently "returned" regardless of any AP. (even for cases where it should not have returned), whereas you just wanted to log a warning.
if (netdev->aborting)
l_warn("aborting");
// do nothing, just return
return;
Hence in our case it started working.
Please mark the thread as "[Solved]"
Last edited by amish (2019-04-06 01:59:51)
Offline