FS#58457 - [linux] wifi connection gets lost frequently - iwlwifi: no beacon heard
Attached to Project:
Arch Linux
Opened by Karen Eliot (kareliot) - Friday, 04 May 2018, 14:24 GMT
Last edited by Jelle van der Waa (jelly) - Thursday, 14 September 2023, 17:54 GMT
Opened by Karen Eliot (kareliot) - Friday, 04 May 2018, 14:24 GMT
Last edited by Jelle van der Waa (jelly) - Thursday, 14 September 2023, 17:54 GMT
|
Details
Description:
wifi connection is very unstable and not usable dmesg shows a lot of: iwlwifi 0000:02:00.0: No beacon heard and the time event is over already... this started after a update from linux-firmware 20180314.4c0bf11-1 to 20180416.b562d2f-1 but downgrading back to the previous version did not help so the problem is probably elsewhere. |
This task depends upon
Closed by Jelle van der Waa (jelly)
Thursday, 14 September 2023, 17:54 GMT
Reason for closing: Deferred
Additional comments about closing: Old kernel, please retry with the latest
Thursday, 14 September 2023, 17:54 GMT
Reason for closing: Deferred
Additional comments about closing: Old kernel, please retry with the latest
$ cat iwlmvm.conf
options iwlmvm power_scheme=1
$ cat iwlwifi.conf
options iwlwifi bt_coex_active=0 11n_disable=1 swcrypto=1
[ 1002.842515] wlp2s0: authenticate with 64:bc:0c:XX:XX:XX
[ 1002.845745] wlp2s0: send auth to 64:bc:0c:XX:XX:XX (try 1/3)
[ 1002.935383] wlp2s0: authenticated
[ 1003.459528] iwlwifi 0000:02:00.0: No beacon heard and the time event is over already...
[ 1003.459567] wlp2s0: Connection to AP 64:bc:0c:XX:XX:XX lost
[ 1007.850856] wlp2s0: aborting authentication with 64:bc:0c:XX:XX:XX by local choice (Reason: 3=DEAUTH_LEAVING)
[ 1008.867258] wlp2s0: authenticate with 64:bc:0c:XX:XX:XX
[ 1008.870413] wlp2s0: send auth to 64:bc:0c:XX:XX:XX (try 1/3)
[ 1008.949300] wlp2s0: authenticated
[ 1009.484241] iwlwifi 0000:02:00.0: No beacon heard and the time event is over already...
I tried 2,4Ghz and 5Ghz. Changed the SSID. Without WPA2 security the connection established. After change the WPA2-PSK, the connection established, too. But next day, i had problems again.
[ 70.360045] wlan0: authenticate with XX:XX:XX:XX:XX:XX
[ 70.369449] wlan0: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
[ 70.377464] wlan0: authenticated
[ 70.983431] iwlwifi 0000:3d:00.0: No beacon heard and the time event is over already...
[ 70.983511] wlan0: Connection to AP XX:XX:XX:XX:XX:XX lost
[ 75.370060] wlan0: aborting authentication with XX:XX:XX:XX:XX:XX by local choice (Reason: 3=DEAUTH_LEAVING)
Kernel 4.16.13-1-ARCH, linux-firmware 20180518.2a9b2cf-1
core/linux 4.17.11-1
core/linux-firmware 20180717.8d69bab-1
linux-firmware 20180825.fea76a0-1
linux 4.18.12.arch1-1
Host: 20L7CTO1WW ThinkPad T480s
Kernel: 4.16.18-rt12-MANJARO
Ethernet controller: Intel Corporation Ethernet Connection (4) I219-LM (rev 21)
Network controller: Intel Corporation Wireless 8265 / 8275 (rev 78)
A few questions:
- Which version of linux-firmware do you have?
- Are you running Manjaro? Or did you use a Manjaro kernel package on Arch?
- What patches are applied to that kernel? Do you have a link for the kernel PKGBUILD and any patch files that go with it?
I am running Manjaro. I am not sure how to identify which patches have been applied to the kernel. I installed the 4.16 realtime kernel on October 19th. I insalled the kernel via the GUI Manjaro Settings Manager's Kernel tool, I am unsure of how to get the PKGBUILD/patch files.
the same problem to me, dmesg -w report these messages:
[ 8455.981979] wlo1: authenticate with b4:f7:a1:e3:68:1d
[ 8455.987901] wlo1: send auth to b4:f7:a1:e3:68:1d (try 1/3)
[ 8455.991267] wlo1: authenticated
[ 8456.601789] iwlwifi 0000:08:00.0: No beacon heard and the time event is over already...
[ 8456.601865] wlo1: Connection to AP b4:f7:a1:e3:68:1d lost
[ 8460.988448] wlo1: aborting authentication with b4:f7:a1:e3:68:1d by local choice (Reason: 3=DEAUTH_LEAVING)
[ 8462.749372] wlo1: authenticate with b4:f7:a1:e3:68:1d
[ 8462.755771] wlo1: send auth to b4:f7:a1:e3:68:1d (try 1/3)
[ 8462.761244] wlo1: authenticated
[ 8463.369607] iwlwifi 0000:08:00.0: No beacon heard and the time event is over already...
[ 8463.369673] wlo1: Connection to AP b4:f7:a1:e3:68:1d lost
[ 8466.357846] audit: type=1131 audit(1541593769.544:291): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 8467.760639] wlo1: aborting authentication with b4:f7:a1:e3:68:1d by local choice (Reason: 3=DEAUTH_LEAVING)
[ 8469.906374] wlo1: authenticate with b4:f7:a1:e3:68:1d
[ 8469.913656] wlo1: send auth to b4:f7:a1:e3:68:1d (try 1/3)
[ 8469.917575] wlo1: authenticated
[ 8470.527521] iwlwifi 0000:08:00.0: No beacon heard and the time event is over already...
[ 8470.527591] wlo1: Connection to AP b4:f7:a1:e3:68:1d lost
[ 8474.916054] wlo1: aborting authentication with b4:f7:a1:e3:68:1d by local choice (Reason: 3=DEAUTH_LEAVING)
[ 8481.347744] IPv6: ADDRCONF(NETDEV_UP): wlo1: link is not ready
[ 8481.360086] IPv6: ADDRCONF(NETDEV_UP): wlo1: link is not ready
[ 8484.476066] IPv6: ADDRCONF(NETDEV_UP): wlo1: link is not ready
[ 8485.418003] wlo1: authenticate with b4:f7:a1:e3:68:1d
[ 8485.424363] wlo1: send auth to b4:f7:a1:e3:68:1d (try 1/3)
[ 8485.429494] wlo1: authenticated
[ 8485.434403] wlo1: associate with b4:f7:a1:e3:68:1d (try 1/3)
[ 8485.450274] wlo1: RX AssocResp from b4:f7:a1:e3:68:1d (capab=0x1131 status=0 aid=1)
[ 8485.451819] wlo1: associated
[ 8485.500164] IPv6: ADDRCONF(NETDEV_CHANGE): wlo1: link becomes ready
I forget if happened in 2017, but this year(2018) when I try to connect to 2.4G or 5G wifi, it reports these and it's hard to connect to the wifi
So far I'm having much better results with linux-firmware 20181018.d877533-1 and linux 4.18.16.arch1-1. I'm not ready to call it completely solved yet, as I've been wrong before. But it's working fine on a 2.4GHz AP that I couldn't connect to at all before.
For example (using network manager):
- start connected to SSID_A
- run: nmcli con up SSID_B
- connection fails with "No beacon heard and the time event is over already..."
- eventually, it aborts and connects back to SSID_A
vs
- start connected to SSID_A
- run: nmcli con down SSID_A; nmcli con up SSID_B
- successfully connects to SSID_B
Connecting from a known network to a known network fails.
wpa_supplicant[801]: wlp4s0: SME: Trying to authenticate with 44:4e:6d:9f:88:c9 (SSID='MyNetwork' freq=2462 MHz)
kernel: wlp4s0: authenticate with 44:4e:6d:9f:88:c9
NetworkManager[6509]: <info> [1550185747.2651] device (wlp4s0): supplicant interface state: inactive -> authenticating
kernel: wlp4s0: send auth to 44:4e:6d:9f:88:c9 (try 1/3)
kernel: wlp4s0: authenticated
kernel: iwlwifi 0000:04:00.0: No beacon heard and the time event is over already...
kernel: wlp4s0: Connection to AP 44:4e:6d:9f:88:c9 lost
org.gnome.Shell.desktop[895]: [2539:2551:0215/000909.332110:ERROR:connection_factory_impl.cc(411)] Failed to connect to MCS endpoint with error -106
kernel: wlp4s0: aborting authentication with 44:4e:6d:9f:88:c9 by local choice (Reason: 3=DEAUTH_LEAVING)
NetworkManager[6509]: <info> [1550185752.2840] device (wlp4s0): supplicant interface state: authenticating -> disconnected
NetworkManager[6509]: <info> [1550185752.3847] device (wlp4s0): supplicant interface state: disconnected -> scanning
but connecting from a known or no network to a new network succeeded.
A workaround is to delete the current active network and then connect to the new one.
However, I can connect to a new SSID after rebooting the computer.
It seems that I cannot connect to a new SSID after the computer waking up from sleep.
My network controller is:
3b:00.0 Network controller [0280]: Intel Corporation Wireless 8265 / 8275 [8086:24fd] (rev 78)
Subsystem: Intel Corporation Dual Band Wireless-AC 8265 [8086:1010]
Flags: bus master, fast devsel, latency 0, IRQ 17
Memory at dc000000 (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 xx-xx-xx-xx-xx-xx-xx-xx
Capabilities: [14c] Latency Tolerance Reporting
Capabilities: [154] L1 PM Substates
Kernel driver in use: iwlwifi
Kernel modules: iwlwifi
I am able to connect to 2.4GHz network without problems, but I cannot connect to a 5GHz WiFi on the same router, with the same authentication if I have been already connected to the 2.4GHz network. The only way to do disable autoconnect, reboot and manually (in NetworkManager GUI) connect to the 5GHz network.
The error is:
kernel: iwlwifi 0000:02:00.0: No beacon heard and the time event is over already...
My hardware is:
02:00.0 Network controller: Intel Corporation Wireless 7260 (rev 73)
I can connect fine to a 5GHz network, but not anymore to a 2.4GHz network.
2 other devices a x220 (running windows) and a x230 (running current ubuntu) are connecting fine to the same wifi, so i think it's something broken with the module/kernel?
I see the error:
kernel: iwlwifi 0000:03:00.0: No beacon heard and the time event is over already...
My hardware (on the thinkpad p50) is:
iwlwifi 0000:03:00.0: Detected Intel(R) Dual Band Wireless AC 8260, REV=0x208
My hardware (on the thinkpad t450s) is:
iwlwifi 0000:03:00.0: Detected Intel(R) Dual Band Wireless AC 7265, REV=0x210
The linux-firmware I installed is:
linux-firmware 20190424.4b6cf2b-1
```
[ 8071.768411] iwlwifi 0000:04:00.0: No beacon heard and the time event is over already...
[ 8071.768441] wlp4s0: Connection to AP cc:ce:1e:19:72:0b lost
[ 8077.834062] wlp4s0: authenticate with cc:ce:1e:19:72:0b
[ 8077.836411] wlp4s0: send auth to cc:ce:1e:19:72:0b (try 1/3)
[ 8077.840151] wlp4s0: authenticated
[ 8077.843051] wlp4s0: associate with cc:ce:1e:19:72:0b (try 1/3)
[ 8077.849818] wlp4s0: RX AssocResp from cc:ce:1e:19:72:0b (capab=0x431 status=0 aid=5)
[ 8077.852392] wlp4s0: associated
[ 8092.165788] wlp4s0: Connection to AP cc:ce:1e:19:72:0b lost
[ 8098.243250] wlp4s0: authenticate with cc:ce:1e:19:72:0b
[ 8098.245383] wlp4s0: send auth to cc:ce:1e:19:72:0b (try 1/3)
[ 8098.249637] wlp4s0: authenticated
[ 8098.250129] wlp4s0: associate with cc:ce:1e:19:72:0b (try 1/3)
[ 8098.256645] wlp4s0: RX AssocResp from cc:ce:1e:19:72:0b (capab=0x431 status=0 aid=5)
[ 8098.259105] wlp4s0: associated
[ 8100.463112] wlp4s0: Connection to AP cc:ce:1e:19:72:0b lost
[ 8100.627812] wlp4s0: Connection to AP 00:00:00:00:00:00 lost
[ 8106.624481] wlp4s0: authenticate with cc:ce:1e:19:72:0b
[ 8106.626731] wlp4s0: send auth to cc:ce:1e:19:72:0b (try 1/3)
[ 8106.631389] wlp4s0: authenticated
[ 8106.633654] wlp4s0: associate with cc:ce:1e:19:72:0b (try 1/3)
[ 8106.639875] wlp4s0: RX AssocResp from cc:ce:1e:19:72:0b (capab=0x431 status=0 aid=5)
[ 8106.642417] wlp4s0: associated
[ 8107.240966] iwlwifi 0000:04:00.0: No beacon heard and the time event is over already...
[ 8107.241039] wlp4s0: Connection to AP cc:ce:1e:19:72:0b lost
[ 8113.355183] wlp4s0: authenticate with cc:ce:1e:19:72:0b
[ 8113.357224] wlp4s0: send auth to cc:ce:1e:19:72:0b (try 1/3)
[ 8113.361117] wlp4s0: authenticated
[ 8113.363822] wlp4s0: associate with cc:ce:1e:19:72:0b (try 1/3)
[ 8113.373790] wlp4s0: RX AssocResp from cc:ce:1e:19:72:0b (capab=0x431 status=0 aid=5)
[ 8113.377646] wlp4s0: associated
[ 8115.516461] wlp4s0: Connection to AP cc:ce:1e:19:72:0b lost
[ 8115.680744] wlp4s0: Connection to AP 00:00:00:00:00:00 lost
[ 8121.672885] wlp4s0: authenticate with cc:ce:1e:19:72:0b
[ 8121.675143] wlp4s0: send auth to cc:ce:1e:19:72:0b (try 1/3)
[ 8121.678981] wlp4s0: authenticated
[ 8121.680704] wlp4s0: associate with cc:ce:1e:19:72:0b (try 1/3)
[ 8121.687370] wlp4s0: RX AssocResp from cc:ce:1e:19:72:0b (capab=0x431 status=0 aid=5)
[ 8121.691464] wlp4s0: associated
[ 8122.289320] iwlwifi 0000:04:00.0: No beacon heard and the time event is over already...
```
HW:
Intel Intel Corporation Wireless 3165 (rev 81)
linux-firmware:
linux-firmware 20190514.711d329-1 (base)
/proc/version:
Linux version 5.1.4-arch1-1-ARCH (builduser@heftig-28985) (gcc version 8.3.0 (GCC)) #1 SMP PREEMPT Wed May 22 08:06:56 UTC 2019
Any help / bugfix would be appreciated :)
Please follow https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging and open a new bug report on https://bugzilla.kernel.org Product Drivers Component network-wireless
ath10k has been adding airtime based queues, I'm not sure that the firmware / driver I've got has those changes yet, but just comes to mind since the errors I see seem to be timeouts / not receiving acks.
Dec 01 04:57:57 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Dec 01 04:57:27 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: disconnected due to excessive missing ACKs
[user@ap ~]$ pacman -Q linux-lts linux-firmware
linux-lts 4.19.84-1
linux-firmware 20190923.417a9c6-1
[user@ap ~]$ dmesg | grep ath10
[ 7.214732] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[ 7.485097] ath10k_pci 0000:01:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043202ff sub 0000:0000
[ 7.485103] ath10k_pci 0000:01:00.0: kconfig debug 1 debugfs 1 tracing 1 dfs 0 testmode 0
[ 7.485461] ath10k_pci 0000:01:00.0: firmware ver 10.2.4-1.0-00045 api 5 features no-p2p,raw-mode,mfp,allows-mesh-bcast crc32 ccbd5104
[ 7.528393] ath10k_pci 0000:01:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08
[ 8.948544] ath10k_pci 0000:01:00.0: htt-ver 2.1 wmi-op 5 htt-op 2 cal otp max-sta 128 raw 0 hwcrypto 1
[ 9.101248] ath10k_pci 0000:01:00.0 wlp1s0: renamed from wlan0
[ 12.610504] ath10k_pci 0000:01:00.0: pdev param 0 not supported by firmware
[ 17.516191] ath10k_pci 0000:01:00.0: pdev param 0 not supported by firmware
[user@ap ~]$ modinfo ath10k_pci
filename: /lib/modules/4.19.84-1-lts/kernel/drivers/net/wireless/ath/ath10k/ath10k_pci.ko.xz
firmware: ath10k/QCA9377/hw1.0/board.bin
firmware: ath10k/QCA9377/hw1.0/firmware-5.bin
firmware: ath10k/QCA9377/hw1.0/firmware-6.bin
firmware: ath10k/QCA6174/hw3.0/board-2.bin
firmware: ath10k/QCA6174/hw3.0/board.bin
firmware: ath10k/QCA6174/hw3.0/firmware-6.bin
firmware: ath10k/QCA6174/hw3.0/firmware-5.bin
firmware: ath10k/QCA6174/hw3.0/firmware-4.bin
firmware: ath10k/QCA6174/hw2.1/board-2.bin
firmware: ath10k/QCA6174/hw2.1/board.bin
firmware: ath10k/QCA6174/hw2.1/firmware-5.bin
firmware: ath10k/QCA6174/hw2.1/firmware-4.bin
firmware: ath10k/QCA9887/hw1.0/board-2.bin
firmware: ath10k/QCA9887/hw1.0/board.bin
firmware: ath10k/QCA9887/hw1.0/firmware-5.bin
firmware: ath10k/QCA988X/hw2.0/board-2.bin
firmware: ath10k/QCA988X/hw2.0/board.bin
firmware: ath10k/QCA988X/hw2.0/firmware-5.bin
firmware: ath10k/QCA988X/hw2.0/firmware-4.bin
firmware: ath10k/QCA988X/hw2.0/firmware-3.bin
firmware: ath10k/QCA988X/hw2.0/firmware-2.bin
license: Dual BSD/GPL
description: Driver support for Qualcomm Atheros 802.11ac WLAN PCIe/AHB devices
author: Qualcomm Atheros
srcversion: 9FE0E3C9ABD99335286A872
alias: pci:v0000168Cd00000050sv*sd*bc*sc*i*
alias: pci:v0000168Cd00000042sv*sd*bc*sc*i*
alias: pci:v0000168Cd00000046sv*sd*bc*sc*i*
alias: pci:v0000168Cd00000056sv*sd*bc*sc*i*
alias: pci:v0000168Cd00000040sv*sd*bc*sc*i*
alias: pci:v0000168Cd0000003Esv*sd*bc*sc*i*
alias: pci:v0000168Cd00000041sv*sd*bc*sc*i*
alias: pci:v0000168Cd0000003Csv*sd*bc*sc*i*
alias: pci:v00000777d000011ACsv*sd*bc*sc*i*
alias: of:N*T*Cqcom,ipq4019-wifiC*
alias: of:N*T*Cqcom,ipq4019-wifi
depends: ath10k_core
retpoline: Y
intree: Y
name: ath10k_pci
vermagic: 4.19.84-1-lts SMP mod_unload
sig_id: PKCS#7
signer: Build time autogenerated kernel key
sig_key: 51:6C:FF:48:E2:26:98:CC:24:DB:B4:41:9B:12:81:B3:7C:BC:86:FD
sig_hashalgo: sha512
signature: 21:22:D0:AC:13:AD:5E:65:0D:5D:3F:A3:16:5B:7E:D8:90:D3:AF:A9:
6F:A4:AE:B1:32:EF:9D:0F:FF:F8:76:43:B4:63:01:E9:DE:76:B8:CF:
B2:7B:AE:B4:A4:E9:EF:5F:72:6B:B6:96:B1:CC:45:E0:76:A0:AB:80:
A2:A6:0B:82:3D:CE:E2:7F:3B:BA:A9:61:3A:F1:1C:A5:66:A9:5E:1F:
AF:5C:BD:09:3F:27:5B:C8:82:53:3B:63:BB:80:92:A0:D8:85:D1:3A:
D2:CA:1D:C6:B0:E6:05:7E:05:5F:1E:32:0A:53:9E:2C:1B:84:CC:D9:
41:DD:98:D4:72:ED:9D:2D:A1:D3:5C:B8:C5:20:95:25:E6:39:FD:7A:
66:51:C4:FF:5D:A6:34:6B:F8:7A:12:25:0E:00:06:C4:9A:9D:7E:06:
28:D2:04:5C:4D:1B:D5:62:CA:F4:6A:24:82:22:C2:F3:76:8F:D9:FE:
73:16:0D:07:85:C0:7D:02:14:E7:8B:88:E3:CF:05:49:33:70:2E:9E:
62:93:9B:86:EE:56:73:B5:CB:D1:55:62:D5:3E:2C:72:0B:48:24:F8:
14:0B:EA:3A:37:FF:B1:9F:5E:5F:86:47:7F:6A:55:08:15:39:6C:FF:
4F:04:DB:7B:D7:0B:C6:BF:ED:CD:E4:29:8A:D5:AB:8A:E2:8B:10:78:
C7:F4:CF:1B:E8:1F:A1:20:B2:45:54:3D:17:BD:2F:BB:82:70:F8:EA:
B9:51:10:87:5C:AA:4D:FD:88:30:A7:76:72:8A:AC:3C:1E:96:6D:F5:
09:13:8D:8E:CE:F9:05:15:61:CB:95:6D:69:5E:F5:AF:56:CA:E9:AD:
99:B4:85:76:D1:1B:93:2F:A9:EC:B6:36:84:C8:59:3D:D7:A3:1D:73:
AF:E1:F0:04:60:1D:15:65:DA:62:6E:8C:3A:87:45:1D:B2:9E:F1:6E:
E1:0A:53:93:E7:96:41:D2:B8:3F:74:06:A6:8A:A2:B8:8E:6B:CC:04:
E9:17:75:D5:63:D2:3B:BA:19:87:BF:0D:5B:87:A5:67:42:BA:30:0E:
0A:00:F8:DF:C2:78:A7:52:8E:01:FD:01:3B:0E:43:70:7E:21:38:8D:
0D:E5:4E:1C:F5:8E:D9:C9:5D:3A:F3:C2:D3:FC:07:98:7C:EF:FE:94:
C9:F3:FA:AB:5F:6D:C1:24:7E:17:98:0F:A6:96:41:8D:C4:15:EA:D8:
66:C7:CC:41:62:4C:64:3A:BB:98:B5:31:54:57:92:6A:03:32:E5:B6:
25:8B:BD:E7:01:E4:5A:08:58:E1:F6:2B:B6:A3:8B:66:AF:0E:7A:5F:
14:90:AF:7F:F7:9C:8C:47:5F:5F:DB:E6
parm: irq_mode:0: auto, 1: legacy, 2: msi (default: 0) (uint)
parm: reset_mode:0: auto, 1: warm only (default: 0) (uint)
[user@ap ~]$ journalctl -b -0 -u hostapd@wlp1s0 -r | sed -r -e 's/([a-f0-9]{2}):([a-f0-9]{2}:){4,}/\1:XX:XX:XX:XX:/gi' -e 's/internet/ssid/g' -e 's/([A-F0-9]{2})[A-F0-9]{14}/\1XXXXXXXXXXX/g' -e 's/ ap hostapd/ hostname hostapd/g' -e 's/wlp1s0/wlan0/g' | grep "Dec 01"
Dec 01 11:51:59 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 WPA: pairwise key handshake completed (RSN)
Dec 01 11:51:59 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 RADIUS: starting accounting session 39XXXXXXXXXXX
Dec 01 11:51:59 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 WPA: pairwise key handshake completed (RSN)
Dec 01 11:51:59 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 RADIUS: starting accounting session 39XXXXXXXXXXX
Dec 01 11:51:59 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 48:XX:XX:XX:XX:23
Dec 01 11:51:58 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 IEEE 802.11: associated (aid 5)
Dec 01 11:51:58 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 IEEE 802.11: authenticated
Dec 01 11:51:58 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 IEEE 802.11: associated (aid 5)
Dec 01 11:51:58 hostname hostapd[322]: wlan0: STA 48:XX:XX:XX:XX:23 IEEE 802.11: authenticated
Dec 01 11:51:37 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 48:XX:XX:XX:XX:23
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 8AXXXXXXXXXXX
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 8AXXXXXXXXXXX
Dec 01 05:50:41 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 05:50:41 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 04:57:57 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Dec 01 04:57:57 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Dec 01 04:57:27 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: disconnected due to excessive missing ACKs
Dec 01 04:57:27 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 04:57:27 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: disconnected due to excessive missing ACKs
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 1CXXXXXXXXXXX
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 1CXXXXXXXXXXX
Dec 01 04:34:50 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 04:34:50 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 04:21:01 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session F8XXXXXXXXXXX
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session F8XXXXXXXXXXX
Dec 01 04:19:55 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 04:19:55 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 04:19:52 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 8EXXXXXXXXXXX
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 8EXXXXXXXXXXX
Dec 01 03:30:20 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 03:30:20 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 03:29:57 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 02:53:18 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 02:53:18 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 88XXXXXXXXXXX
Dec 01 02:53:18 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 02:53:18 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 88XXXXXXXXXXX
Dec 01 02:53:18 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 02:53:17 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 02:53:17 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 02:53:17 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 02:53:17 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 02:52:55 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 93XXXXXXXXXXX
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 93XXXXXXXXXXX
Dec 01 01:15:22 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 01:15:22 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 00:14:34 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 25XXXXXXXXXXX
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 WPA: pairwise key handshake completed (RSN)
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 RADIUS: starting accounting session 25XXXXXXXXXXX
Dec 01 00:04:59 hostname hostapd[322]: wlan0: AP-STA-CONNECTED 10:XX:XX:XX:XX:30
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: associated (aid 6)
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 00:04:59 hostname hostapd[322]: wlan0: STA 10:XX:XX:XX:XX:30 IEEE 802.11: authenticated
Dec 01 00:04:58 hostname hostapd[322]: wlan0: AP-STA-DISCONNECTED 10:XX:XX:XX:XX:30
**EDIT**: Can confirm, the problem appears to be fixed after this change.
[ 1719.810647] iwlwifi 0000:21:00.0: No beacon heard and the time event is over already...
[ 1719.810659] wlo1: Connection to AP XX:XX:XX:XX:XX:XX lost
[ 1719.836953] iwlwifi 0000:21:00.0: expected hw-decrypted unicast frame for station.
This wifi adapter is a pain in the ass.
I've had this issue for a while, but it's very intermittent so it's hard for me to capture a trace. If anyone here experiences this issue with some frequency, or if you know of a reliable way to reproduce, I think it would be a great help if you could follow the instructions in the bugzilla link to capture a trace, and apply the patch in comment #28 if you are able.
Basically, what I see, is a success until out of nowhere, "iwlwifi 0000:04:00.0: No beacon heard and the time event is over already..." happens and connection is lost:
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: CTRL-EVENT-CONNECTED - Connection to 38:43:7d:a5:13:d4 completed [id=0 id_str=]
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Set wlp4s0 operstate 0->1 (UP)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Determining shared radio frequencies (max len 2)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Shared frequencies (len=1): completed iteration
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: freq[0]: 5220, flags=0x1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Add operating class 81
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Channels - hexdump(len=13): 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Add operating class 124
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Channels - hexdump(len=4): 95 99 9d a1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Add operating class 125
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Channels - hexdump(len=5): 95 99 9d a1 a5
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: Update channel list
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11,12,13 124:149,153,157,161 125:149,153,157,161,165
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: P2P: cli_channels:
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: External notification - portValid=1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: External notification - EAP success=1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: SUPP_PAE entering state AUTHENTICATING
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: SUPP_BE entering state SUCCESS
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAP: EAP entering state DISABLED
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: SUPP_PAE entering state AUTHENTICATED
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: Supplicant port status: Authorized
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Set supplicant port authorized for 38:43:7d:a5:13:d4
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL: SUPP_BE entering state IDLE
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: EAPOL authentication completed - result=SUCCESS
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Set rekey offload
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: RTM_NEWLINK: ifi_index=3 ifname=wlp4s0 operstate=6 linkmode=1 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
Apr 26 14:33:42 think460s kernel: iwlwifi 0000:04:00.0: No beacon heard and the time event is over already...
Apr 26 14:33:42 think460s kernel: wlp4s0: Connection to AP 38:43:7d:a5:13:d4 lost
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Ignored event 20 (NL80211_CMD_DEL_STATION) for foreign interface (ifindex 3 wdev 0x0)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wlp4s0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Delete station 38:43:7d:a5:13:d4
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Ignored event 39 (NL80211_CMD_DEAUTHENTICATE) for foreign interface (ifindex 3 wdev 0x0)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Drv Event 39 (NL80211_CMD_DEAUTHENTICATE) received for wlp4s0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Deauthenticate event
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Event DEAUTH (11) received
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Deauthentication notification
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: * reason 4 (DISASSOC_DUE_TO_INACTIVITY) locally_generated=1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: * address 38:43:7d:a5:13:d4
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: Deauthentication frame IE(s) - hexdump(len=0): [NULL]
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: CTRL-EVENT-DISCONNECTED bssid=38:43:7d:a5:13:d4 reason=4 locally_generated=1
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Auto connect enabled: try to reconnect (wps=0/0 wpa_state=9)
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Setting scan request: 0.100000 sec
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: Added BSSID 38:43:7d:a5:13:d4 into blacklist
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Blacklist count 1 --> request scan in 100 ms
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Ignore new scan request for 0.100000 sec since an earlier request is scheduled to trigger sooner
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: TDLS: Remove peers on disassociation
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: WPA: Clear old PMK and PTK
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: Disconnect event - remove keys
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wpa_driver_nl80211_set_key: ifindex=3 (wlp4s0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wpa_driver_nl80211_set_key: ifindex=3 (wlp4s0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wpa_driver_nl80211_set_key: ifindex=3 (wlp4s0) alg=0 addr=0x55643dd09b70 key_idx=0 set_tx=0 seq_len=0 key_len=0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: addr=38:43:7d:a5:13:d4
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Data frame filter flags=0x0
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: wlp4s0: State: COMPLETED -> DISCONNECTED
Apr 26 14:33:42 think460s wpa_supplicant[1001329]: nl80211: Set wlp4s0 operstate 1->0 (DORMANT)
Related:
* https://bugzilla.kernel.org/show_bug.cgi?id=204791
Just like justincapella (https://bugs.archlinux.org/task/58457#comment185620) my conclusion is that the ath10k station is at fault.
ath9k stations don't produce this problem.
Connections break also for other devices (including Apple/Android).
To me, this doesn't look like an issue with Arch Linux but an issue with ath10k/openwrt.
The workaround suggested by andreyv (https://bugs.archlinux.org/task/58457#comment185619 - reduing the beacon interval to 50) doesn't resolve the connection issues on my end.
Changing the channel (https://bugs.archlinux.org/task/58457#comment186636) also has no effect for me.
I'm starting a discussion in the openwrt forum.
https://forum.openwrt.org/t/wifi-connectivity-issues-with-ath10k/67779
I've tried a few combinations of openwrt trunk/19.07 and ath10k stock/candelatech for the access point. There were working versions with openwrt-trunk + ath10k-ct and some with openwrt-19.07 + ath10k.
I think it's a weird timing thing maybe we're seeing more frequently now that airtime fairness queues are default. I think it may be fixed in hostapd, but that maybe some queued packets are not destroyed on disconnect
linux-firmware==20200817.7a30af1-1
linux=5.8.10.arch1-1
Linux 5.8.10-arch1-1 #1 SMP PREEMPT Thu, 17 Sep 2020 18:01:06 +0000 x86_64 GNU/Linux
Client Wireles:
00:14.3 Network controller: Intel Corporation Cannon Point-LP CNVi [Wireless-AC] (rev 30)
Subsystem: Intel Corporation Device 0034
Kernel driver in use: iwlwifi
Kernel modules: iwlwifi
AP:
https://openwrt.org/toh/asus/rt-ac58u currently running OpenWrt 18.06.4 r7808-ef686b7292
Beacon interval is set to default (100). I started seeing disconnects after a recent kernel upgrade this month. Setting the following modprobe options seems to work so far:
options iwlmvm power_scheme=1
options iwlwifi power_save=0
Also no problems with old laptop and intel 8265 / 8275 (rev 78) on it.
[1] https://bugzilla.kernel.org/attachment.cgi?id=294585&action=diff