Description of problem: ~~~ Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: disconnect from AP 58:6d:8f:ae:c1:93 for new auth to 58:6d:8f:ae:c1:94 Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: authenticate with 58:6d:8f:ae:c1:94 Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: send auth to 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:34:38 localhost.localdomain NetworkManager[992]: <info> [1500032078.7089] device (wlp58s0): supplicant interface state: completed -> authenticating Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: authenticated Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: associate with 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: RX AssocResp from 58:6d:8f:ae:c1:94 (capab=0x11 status=0 aid=1) Jul 14 13:34:38 localhost.localdomain kernel: wlp58s0: associated Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Associated with 58:6d:8f:ae:c1:94 Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:94 [PTK=CCMP GTK=CCMP] Jul 14 13:34:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:94 completed [id=0 id_str=] Jul 14 13:34:38 localhost.localdomain NetworkManager[992]: <info> [1500032078.7319] device (wlp58s0): supplicant interface state: authenticating -> associated Jul 14 13:34:38 localhost.localdomain NetworkManager[992]: <info> [1500032078.7447] device (wlp58s0): supplicant interface state: associated -> 4-way handshake Jul 14 13:34:38 localhost.localdomain NetworkManager[992]: <info> [1500032078.7456] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ... snip ... Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:93 (SSID='VitaLinksysE4200' freq=2462 MHz) Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: disconnect from AP 58:6d:8f:ae:c1:94 for new auth to 58:6d:8f:ae:c1:93 Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: authenticate with 58:6d:8f:ae:c1:93 Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: send auth to 58:6d:8f:ae:c1:93 (try 1/3) Jul 14 13:36:38 localhost.localdomain NetworkManager[992]: <info> [1500032198.8228] device (wlp58s0): supplicant interface state: completed -> authenticating Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:93 (SSID='VitaLinksysE4200' freq=2462 MHz) Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: authenticated Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: associate with 58:6d:8f:ae:c1:93 (try 1/3) Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: RX AssocResp from 58:6d:8f:ae:c1:93 (capab=0x411 status=0 aid=2) Jul 14 13:36:38 localhost.localdomain kernel: wlp58s0: associated Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Associated with 58:6d:8f:ae:c1:93 Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 14 13:36:38 localhost.localdomain NetworkManager[992]: <info> [1500032198.8508] device (wlp58s0): supplicant interface state: authenticating -> associating Jul 14 13:36:38 localhost.localdomain NetworkManager[992]: <info> [1500032198.8551] device (wlp58s0): supplicant interface state: associating -> associated Jul 14 13:36:38 localhost.localdomain NetworkManager[992]: <info> [1500032198.8644] device (wlp58s0): supplicant interface state: associated -> 4-way handshake Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:93 [PTK=CCMP GTK=CCMP] Jul 14 13:36:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:93 completed [id=0 id_str=] Jul 14 13:36:38 localhost.localdomain NetworkManager[992]: <info> [1500032198.8771] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ... snip ... Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: disconnect from AP 58:6d:8f:ae:c1:93 for new auth to 58:6d:8f:ae:c1:94 Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: authenticate with 58:6d:8f:ae:c1:94 Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: send auth to 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:46:38 localhost.localdomain NetworkManager[992]: <info> [1500032798.8240] device (wlp58s0): supplicant interface state: completed -> authenticating Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: authenticated Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: associate with 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: RX AssocResp from 58:6d:8f:ae:c1:94 (capab=0x11 status=0 aid=1) Jul 14 13:46:38 localhost.localdomain kernel: wlp58s0: associated Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Associated with 58:6d:8f:ae:c1:94 Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 14 13:46:38 localhost.localdomain NetworkManager[992]: <info> [1500032798.8467] device (wlp58s0): supplicant interface state: authenticating -> associating Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:94 [PTK=CCMP GTK=CCMP] Jul 14 13:46:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:94 completed [id=0 id_str=] Jul 14 13:46:38 localhost.localdomain NetworkManager[992]: <info> [1500032798.8629] device (wlp58s0): supplicant interface state: associating -> 4-way handshake Jul 14 13:46:38 localhost.localdomain NetworkManager[992]: <info> [1500032798.8634] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ... snip ... Jul 14 13:50:36 localhost.localdomain audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=fprintd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? Jul 14 13:50:38 localhost.localdomain kernel: nfs: server nfs-01.eng.brq.redhat.com not responding, timed out Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:93 (SSID='VitaLinksysE4200' freq=2462 MHz) Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: disconnect from AP 58:6d:8f:ae:c1:94 for new auth to 58:6d:8f:ae:c1:93 Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: authenticate with 58:6d:8f:ae:c1:93 Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: send auth to 58:6d:8f:ae:c1:93 (try 1/3) Jul 14 13:50:38 localhost.localdomain NetworkManager[992]: <info> [1500033038.6469] device (wlp58s0): supplicant interface state: completed -> authenticating Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:93 (SSID='VitaLinksysE4200' freq=2462 MHz) Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: authenticated Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: associate with 58:6d:8f:ae:c1:93 (try 1/3) Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: RX AssocResp from 58:6d:8f:ae:c1:93 (capab=0x411 status=0 aid=2) Jul 14 13:50:38 localhost.localdomain NetworkManager[992]: <info> [1500033038.6636] device (wlp58s0): supplicant interface state: authenticating -> associating Jul 14 13:50:38 localhost.localdomain kernel: wlp58s0: associated Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Associated with 58:6d:8f:ae:c1:93 Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 14 13:50:38 localhost.localdomain NetworkManager[992]: <info> [1500033038.6843] device (wlp58s0): supplicant interface state: associating -> associated Jul 14 13:50:38 localhost.localdomain NetworkManager[992]: <info> [1500033038.6942] device (wlp58s0): supplicant interface state: associated -> 4-way handshake Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:93 [PTK=CCMP GTK=CCMP] Jul 14 13:50:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:93 completed [id=0 id_str=] Jul 14 13:50:38 localhost.localdomain NetworkManager[992]: <info> [1500033038.7122] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ... snip ... Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: disconnect from AP 58:6d:8f:ae:c1:93 for new auth to 58:6d:8f:ae:c1:94 Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: authenticate with 58:6d:8f:ae:c1:94 Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: send auth to 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:52:38 localhost.localdomain NetworkManager[992]: <info> [1500033158.8307] device (wlp58s0): supplicant interface state: completed -> authenticating Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: authenticated Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: associate with 58:6d:8f:ae:c1:94 (try 1/3) Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: RX AssocResp from 58:6d:8f:ae:c1:94 (capab=0x11 status=0 aid=1) Jul 14 13:52:38 localhost.localdomain kernel: wlp58s0: associated Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: Associated with 58:6d:8f:ae:c1:94 Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:94 [PTK=CCMP GTK=CCMP] Jul 14 13:52:38 localhost.localdomain wpa_supplicant[1109]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:94 completed [id=0 id_str=] Jul 14 13:52:38 localhost.localdomain NetworkManager[992]: <info> [1500033158.8753] device (wlp58s0): supplicant interface state: authenticating -> associated Jul 14 13:52:38 localhost.localdomain NetworkManager[992]: <info> [1500033158.8764] device (wlp58s0): supplicant interface state: associated -> 4-way handshake Jul 14 13:52:38 localhost.localdomain NetworkManager[992]: <info> [1500033158.8767] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ~~~ It is interesting to see that there is some pattern. It tries to reconnect every 38th second and it is always even minute. The shortest interval appears to be 120 seconds. Version-Release number of selected component (if applicable): I observe this behavior on Lenovo T470s if that might be hardware specific. $ rpm -q NetworkManager NetworkManager-1.8.0-6.fc27.x86_64 $ rpm -q kernel kernel-4.11.0-2.fc26.x86_64 kernel-4.12.0-0.rc7.git2.1.fc27.x86_64 kernel-4.12.0-1.fc27.x86_64 $ uname -a Linux localhost.localdomain 4.12.0-1.fc27.x86_64 #1 SMP Mon Jul 3 15:45:36 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux How reproducible: Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
Hi Vit, IIRC, NetworkManager will trigger periodic scans every two minutes to allow promptly roaming in the case current WiFi network signal is low and another with the same SSID and better signal is available: yes, those are the 120 seconds you can see as the base unit interval between the two disconnections. Looking at the logs, the two WiFi networks have two consecutive BSSIDs: these let me guess that you have an AP advertising the same WiFi network on both 2.4 and 5GHz. My guess for the issue is that you are not very near the AP and the signal you get is not that great: every two minutes, when there is a new WiFi network scan, both the 2.4 and 5Ghz networks will be detected: if the beacon from the one you are not connected to is received with higher power that the other one your laptop will roam to the other frequency: as you are equally distant from both, you will get once a little more strong beacon from one and maybe the other round from the other. This should not happen if you are very near the AP. In this case the behavior seems correct... but of course you want to disable roaming for this case and connect to a specific one of the two (I would advice to the 5GHz one). You can achieve this by setting a fixed bssid in the NM wifi connection: nmcli conn modify VitaLinksysE4200Y 802-11-wireless.bssid 58:6d:8f:ae:c1:94 which will also completely disable the background scan. Can you please check if this would solve your issue? Thanks Francesco
Hi Francesco, Thanks for elaboration. Your explanation seems plausible. I'll need to test the proposed solution as soon as I'll get my LP home again. Nevertheless, I consider the proposed solution just workaround. Is it the roaming algorithm really that simple to choose the AP just by signal strength? E.g. if strength was between 0-100, while AP 1 had strength 57 while AP 2 had strength 58, the AP 2 would be chosen? Is there some range, where the current connection had preference? Is there a way to adjust the range?
(In reply to Francesco Giudici from comment #1) Hmm, so I was connected and did what you proposed during connection: ~~~ nmcli conn modify VitaLinksysE4200Y 802-11-wireless.bssid 58:6d:8f:ae:c1:94 ~~~ But again I was reconnected. Going to switch off WiFi and reconnect if that makes any difference ...
So after reconnection, the WiFi was stable for almost 3 days, although one reconnect happened, not sure why: ~~~ Jul 28 10:31:54 localhost.localdomain wpa_supplicant[1158]: wlp58s0: CTRL-EVENT-DISCONNECTED bssid=58:6d:8f:ae:c1:94 reason=4 locally_generated=1 Jul 28 10:31:54 localhost.localdomain NetworkManager[945]: <warn> [1501230714.2741] sup-iface[0x55f53adf2830,wlp58s0]: connection disconnected (reason -4) Jul 28 10:31:54 localhost.localdomain NetworkManager[945]: <info> [1501230714.2917] device (wlp58s0): supplicant interface state: completed -> disconnected Jul 28 10:31:54 localhost.localdomain NetworkManager[945]: <info> [1501230714.3797] device (wlp58s0): supplicant interface state: disconnected -> scanning Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: SME: Trying to authenticate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 28 10:31:55 localhost.localdomain NetworkManager[945]: <info> [1501230715.2507] device (wlp58s0): supplicant interface state: scanning -> authenticating Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: Trying to associate with 58:6d:8f:ae:c1:94 (SSID='VitaLinksysE4200' freq=5220 MHz) Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: Associated with 58:6d:8f:ae:c1:94 Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jul 28 10:31:55 localhost.localdomain NetworkManager[945]: <info> [1501230715.2619] device (wlp58s0): supplicant interface state: authenticating -> associated Jul 28 10:31:55 localhost.localdomain NetworkManager[945]: <info> [1501230715.2699] device (wlp58s0): supplicant interface state: associated -> 4-way handshake Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: WPA: Key negotiation completed with 58:6d:8f:ae:c1:94 [PTK=CCMP GTK=CCMP] Jul 28 10:31:55 localhost.localdomain wpa_supplicant[1158]: wlp58s0: CTRL-EVENT-CONNECTED - Connection to 58:6d:8f:ae:c1:94 completed [id=0 id_str=] Jul 28 10:31:55 localhost.localdomain NetworkManager[945]: <info> [1501230715.2883] device (wlp58s0): supplicant interface state: 4-way handshake -> completed ~~~
(In reply to Vít Ondruch from comment #2) > Hi Francesco, > > Thanks for elaboration. Your explanation seems plausible. I'll need to test > the proposed solution as soon as I'll get my LP home again. > > Nevertheless, I consider the proposed solution just workaround. Is it the > roaming algorithm really that simple to choose the AP just by signal > strength? E.g. if strength was between 0-100, while AP 1 had strength 57 > while AP 2 had strength 58, the AP 2 would be chosen? Is there some range, > where the current connection had preference? Is there a way to adjust the > range? I think this will be solved by: https://bugzilla.gnome.org/show_bug.cgi?id=766482 which basically disables automatic scanning while the signal is good enough.
This bug appears to have been reported against 'rawhide' during the Fedora 27 development cycle. Changing version to '27'.
This message is a reminder that Fedora 27 is nearing its end of life. On 2018-Nov-30 Fedora will stop maintaining and issuing updates for Fedora 27. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '27'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 27 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 27 changed to end-of-life (EOL) status on 2018-11-30. Fedora 27 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.