WiFi-Issue: Regularily disconnecting, due to Mesh? CTRL-EVENT-SUBNET-S

PeerK · 2024-09-07 22:18:40

Hi all,

I observe an annoying issue with my notebook WiFi (Lenovo Yoga 7, Intel AX210/AX1675) and need a helping hand.

The Connection sets up pretty well (886 MBit/s), but from time to time (< 10 Minutes) it disconnects and the connection breaks down for a second.

Edit: I have a AVM Cable Router (FB 6591) with two satellites (FB 7580). And I am sitting pretty in the middle of the base station and one of the satellites. It might be, that "CTRL-EVENT-SUBNET-STATUS-UPDATE" indicates an attempt to switch from the satellite to the base station that produces a short disconnect.(?)

I read the advice from another thread to disable the power management and added "pcie_aspm=off" the kernel parameters:

$ cat /proc/cmdline

initrd=\initramfs-linux.img cryptdevice=UUID=b5cc7900-2ddf-4735-9c38-8e819fdcc162:luks root=/dev/mapper/hog5crypt-root pcie_aspm=off rw

as well as some entries to /etc/modprobe.d/iwlwifi.conf. But this has not changed anything.

$ cat /etc/modprobe.d/iwlwifi.conf

options iwlmvm power_scheme=1
options iwlwifi power_level=5
options iwlwifi power_save=false

Here some further Wi-Fi information:

$ systool -vm iwlwifi

Module = "iwlwifi"

  Attributes:
    coresize            = "593920"
    initsize            = "0"
    initstate           = "live"
    refcnt              = "1"
    srcversion          = "9B0C961B7FF85E88CEB72B0"
    taint               = ""
    uevent              = <store method only>

  Parameters:
    11n_disable         = "0"
    amsdu_size          = "0"
    bt_coex_active      = "Y"
    debug               = "0"
    disable_11ac        = "N"
    disable_11ax        = "N"
    disable_11be        = "N"
    enable_ini          = "16"
    fw_restart          = "Y"
    led_mode            = "0"
    nvm_file            = "(null)"
    power_level         = "5"
    power_save          = "N"
    remove_when_gone    = "N"
    swcrypto            = "0"
    uapsd_disable       = "3"

  Sections:

and

$ systool -vm iwlmvm

Module = "iwlmvm"

  Attributes:
    coresize            = "749568"
    initsize            = "0"
    initstate           = "live"
    refcnt              = "0"
    srcversion          = "113410E809DC3CBDC91F077"
    taint               = ""
    uevent              = <store method only>

  Parameters:
    init_dbg            = "N"
    power_scheme        = "1"

  Sections:

lspci -v | less

..
02:00.0 Network controller: Intel Corporation Wi-Fi 6E(802.11ax) AX210/AX1675* 2x2 [Typhoon Peak] (rev 1a)
        Subsystem: Intel Corporation Wi-Fi 6 AX210 160MHz
        Flags: bus master, fast devsel, latency 0, IRQ 41, IOMMU group 14
        Memory at 78d00000 (64-bit, non-prefetchable) [size=16K]
        Capabilities: <access denied>
        Kernel driver in use: iwlwifi
        Kernel modules: iwlwifi

Here the logging of the temporary disconnect (journalctl -b -f). The interesting part starts imho at 23:05:32 with "CTRL-EVENT-SUBNET-STATUS-UPDATE". But I have not a glimpse of an idea, what that means ;-)

..
23:02:55 h5 NetworkManager[910]: <info>  [1725742975.0689] audit: op="statistics" interface="wlp2s0" ifindex=2 args="2000" pid=1317 uid=1000 result="success"
23:02:55 h5 NetworkManager[910]: <info>  [1725742975.0732] audit: op="statistics" interface="wlp2s0" ifindex=2 args="500" pid=1454 uid=1000 result="success"
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  12
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  13
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  14
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  15
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  16
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  17
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  18
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  19
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  12
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  13
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  14
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  15
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  16
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  17
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  18
23:02:58 h5 kmix[1635]: org.kde.kmix: Channel Map contains a pa_channel_position we cannot handle  19
23:03:20 h5 plasmashell[1317]: qt.qpa.wayland: eglSwapBuffers failed with 0x300d, surface: 0x0
23:03:20 h5 plasmashell[1317]: qrc:/qt/qml/org/kde/plasma/components/ScrollView.qml:53:29: QML ScrollBar: Binding loop detected for property "visible"
23:03:20 h5 plasmashell[1317]: qrc:/qt/qml/org/kde/plasma/components/ScrollView.qml:53:29: QML ScrollBar: Binding loop detected for property "visible"
23:03:27 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:03:27 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:04:20 h5 kwin_wayland[1101]: This plugin does not support raise()
23:04:20 h5 kwin_wayland[1101]: This plugin does not support grabbing the keyboard
23:04:22 h5 kwin_wayland[1101]: This plugin does not support raise()
23:04:24 h5 kwin_wayland[1101]: kwin_scene_opengl: 0x4: GL_INVALID_VALUE in glTexSubImage2D(xoffset 0 + width 388 > 387)
23:04:24 h5 kwin_wayland[1101]: This plugin does not support grabbing the keyboard
23:04:24 h5 kwin_wayland[1101]: This plugin does not support grabbing the keyboard
23:04:24 h5 kcmshell6[3270]: Retrieved properties for window QUuid("{bb8e7264-0a8b-4c7c-acfb-248b7e7cbc8c}")
23:04:25 h5 kcmshell6[3270]: qrc:/kcm/kcm_kwinrules/RulesEditor.qml:173:5: QML OverlaySheet: Binding loop detected for property "implicitHeight"
23:04:25 h5 kcmshell6[3270]: qrc:/qt/qml/org/kde/kirigami/dialogs/Dialog.qml:344:18: QML ScrollView: Binding loop detected for property "calculatedImplicitWidth"
23:04:25 h5 kcmshell6[3270]: qrc:/qt/qml/org/kde/kirigami/dialogs/Dialog.qml:344:18: QML ScrollView: Binding loop detected for property "calculatedImplicitHeight"
23:04:25 h5 kcmshell6[3270]: qrc:/qt/qml/org/kde/kirigami/dialogs/Dialog.qml:401:33: QML Binding: Binding loop detected for property "value"
23:04:25 h5 kcmshell6[3270]: qrc:/kcm/kcm_kwinrules/RulesEditor.qml:173:5: QML OverlaySheet: Binding loop detected for property "implicitHeight"
23:04:25 h5 kcmshell6[3270]: qrc:/kcm/kcm_kwinrules/RulesEditor.qml:173:5: QML OverlaySheet: Binding loop detected for property "implicitHeight"
23:04:25 h5 kcmshell6[3270]: qt.qpa.wayland: eglSwapBuffers failed with 0x300d, surface: 0x0
23:04:48 h5 kcmshell6[3270]: file:///usr/lib/qt6/qml/org/kde/kirigami/ActionTextField.qml:118: TypeError: Cannot read property 'verticalCenter' of null
23:05:03 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:05:03 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:05:06 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:05:06 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:05:32 h5 wpa_supplicant[964]: wlp2s0: WNM: Preferred List Available
23:05:32 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with dc:39:6f:be:99:64 (SSID='KL' freq=5220 MHz)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.4114] device (wlp2s0): supplicant interface state: completed -> authenticating
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.4115] device (p2p-dev-wlp2s0): supplicant management interface state: completed -> authenticating
23:05:32 h5 kernel: wlp2s0: disconnect from AP e0:28:6d:6d:59:00 for new auth to dc:39:6f:be:99:64
23:05:32 h5 kernel: wlp2s0: authenticate with dc:39:6f:be:99:64 (local address=10:91:d1:59:1a:d7)
23:05:32 h5 kernel: wlp2s0: send auth to dc:39:6f:be:99:64 (try 1/3)
23:05:32 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with dc:39:6f:be:99:64 (SSID='KL' freq=5220 MHz)
23:05:32 h5 kernel: wlp2s0: authenticate with dc:39:6f:be:99:64 (local address=10:91:d1:59:1a:d7)
23:05:32 h5 kernel: wlp2s0: send auth to dc:39:6f:be:99:64 (try 1/3)
23:05:32 h5 wpa_supplicant[964]: wlp2s0: PMKSA-CACHE-ADDED dc:39:6f:be:99:64 0
23:05:32 h5 wpa_supplicant[964]: wlp2s0: Trying to associate with dc:39:6f:be:99:64 (SSID='KL' freq=5220 MHz)
23:05:32 h5 kernel: wlp2s0: authenticated
23:05:32 h5 kernel: wlp2s0: associate with dc:39:6f:be:99:64 (try 1/3)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.7296] device (wlp2s0): supplicant interface state: authenticating -> associating
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.7297] device (p2p-dev-wlp2s0): supplicant management interface state: authenticating -> associating
23:05:32 h5 kernel: wlp2s0: RX ReassocResp from dc:39:6f:be:99:64 (capab=0x1511 status=0 aid=3)
23:05:32 h5 wpa_supplicant[964]: wlp2s0: Associated with dc:39:6f:be:99:64
23:05:32 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
23:05:32 h5 kernel: wlp2s0: associated
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.7788] device (wlp2s0): supplicant interface state: associating -> 4way_handshake
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.7789] device (p2p-dev-wlp2s0): supplicant management interface state: associating -> 4way_handshake
23:05:32 h5 wpa_supplicant[964]: wlp2s0: WPA: Key negotiation completed with dc:39:6f:be:99:64 [PTK=CCMP GTK=CCMP]
23:05:32 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-CONNECTED - Connection to dc:39:6f:be:99:64 completed [id=0 id_str=]
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8246] device (wlp2s0): supplicant interface state: 4way_handshake -> completed
23:05:32 h5 kernel: wlp2s0: Limiting TX power to 20 (23 - 3) dBm as advertised by dc:39:6f:be:99:64
23:05:32 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-43 noise=9999 txrate=1000
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8465] device (wlp2s0): ip:dhcp4: restarting
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8466] dhcp4 (wlp2s0): canceled DHCP transaction
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8466] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8466] dhcp4 (wlp2s0): state changed no lease
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8467] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8468] device (wlp2s0): ip:dhcp6: restarting
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8469] dhcp6 (wlp2s0): canceled DHCP transaction
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8469] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8469] dhcp6 (wlp2s0): state changed no lease
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8470] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8471] device (p2p-dev-wlp2s0): supplicant management interface state: 4way_handshake -> completed
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.8791] dhcp6 (wlp2s0): state changed new lease, address=2a02:908:69c:8040:86d2:c07b:c543:4585
23:05:32 h5 systemd[1]: Starting Network Manager Script Dispatcher Service...
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.9024] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112, acd pending
23:05:32 h5 NetworkManager[910]: <info>  [1725743132.9033] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112
23:05:32 h5 systemd[1]: Started Network Manager Script Dispatcher Service.
23:05:42 h5 systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
23:05:48 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:05:48 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:00 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:00 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:16 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:16 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:17 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:17 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:20 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:20 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:25 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:25 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:28 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:28 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:30 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:30 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:34 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:07:34 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:09:20 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:09:20 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:09:47 h5 wpa_supplicant[964]: wlp2s0: RSN: Group rekeying completed with dc:39:6f:be:99:64 [GTK=CCMP]
23:10:00 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:00 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:31 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:31 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:35 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with e0:28:6d:6d:59:00 (SSID='KL' freq=5580 MHz)
23:10:35 h5 kernel: wlp2s0: disconnect from AP dc:39:6f:be:99:64 for new auth to e0:28:6d:6d:59:00
23:10:35 h5 kernel: wlp2s0: authenticate with e0:28:6d:6d:59:00 (local address=10:91:d1:59:1a:d7)
23:10:35 h5 NetworkManager[910]: <info>  [1725743435.9235] device (wlp2s0): supplicant interface state: completed -> authenticating
23:10:35 h5 NetworkManager[910]: <info>  [1725743435.9236] device (p2p-dev-wlp2s0): supplicant management interface state: completed -> authenticating
23:10:35 h5 kernel: wlp2s0: send auth to e0:28:6d:6d:59:00 (try 1/3)
23:10:36 h5 wpa_supplicant[964]: wlp2s0: Trying to associate with e0:28:6d:6d:59:00 (SSID='KL' freq=5580 MHz)
23:10:36 h5 kernel: wlp2s0: authenticated
23:10:36 h5 kernel: wlp2s0: associate with e0:28:6d:6d:59:00 (try 1/3)
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.0027] device (wlp2s0): supplicant interface state: authenticating -> associating
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.0027] device (p2p-dev-wlp2s0): supplicant management interface state: authenticating -> associating
23:10:36 h5 kernel: wlp2s0: RX ReassocResp from e0:28:6d:6d:59:00 (capab=0x1511 status=0 aid=1)
23:10:36 h5 kernel: wlp2s0: associated
23:10:36 h5 wpa_supplicant[964]: wlp2s0: Associated with e0:28:6d:6d:59:00
23:10:36 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1064] device (wlp2s0): supplicant interface state: associating -> 4way_handshake
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1065] device (p2p-dev-wlp2s0): supplicant management interface state: associating -> 4way_handshake
23:10:36 h5 kernel: wlp2s0: Limiting TX power to 27 (30 - 3) dBm as advertised by e0:28:6d:6d:59:00
23:10:36 h5 wpa_supplicant[964]: wlp2s0: WPA: Key negotiation completed with e0:28:6d:6d:59:00 [PTK=CCMP GTK=CCMP]
23:10:36 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-CONNECTED - Connection to e0:28:6d:6d:59:00 completed [id=0 id_str=]
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1841] device (wlp2s0): supplicant interface state: 4way_handshake -> completed
23:10:36 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-49 noise=9999 txrate=234000
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1874] device (wlp2s0): ip:dhcp4: restarting
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1875] dhcp4 (wlp2s0): canceled DHCP transaction
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1876] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1876] dhcp4 (wlp2s0): state changed no lease
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1877] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1878] device (wlp2s0): ip:dhcp6: restarting
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1878] dhcp6 (wlp2s0): canceled DHCP transaction
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1879] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1879] dhcp6 (wlp2s0): state changed no lease
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1879] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.1881] device (p2p-dev-wlp2s0): supplicant management interface state: 4way_handshake -> completed
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.2035] dhcp6 (wlp2s0): state changed new lease, address=2a02:908:69c:8040:86d2:c07b:c543:4585
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.2051] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112, acd pending
23:10:36 h5 NetworkManager[910]: <info>  [1725743436.2057] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112
23:10:36 h5 systemd[1]: Starting Network Manager Script Dispatcher Service...
23:10:36 h5 systemd[1]: Started Network Manager Script Dispatcher Service.
23:10:40 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:40 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:41 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:41 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:43 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:43 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:46 h5 systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
23:10:51 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:51 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:55 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:10:55 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:11:03 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:11:03 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:11:47 h5 wpa_supplicant[964]: wlp2s0: WNM: Preferred List Available
23:11:47 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with dc:39:6f:be:99:64 (SSID='KL' freq=5220 MHz)
23:11:48 h5 kernel: wlp2s0: disconnect from AP e0:28:6d:6d:59:00 for new auth to dc:39:6f:be:99:64
23:11:48 h5 kernel: wlp2s0: authenticate with dc:39:6f:be:99:64 (local address=10:91:d1:59:1a:d7)
23:11:48 h5 kernel: wlp2s0: send auth to dc:39:6f:be:99:64 (try 1/3)
23:11:48 h5 NetworkManager[910]: <info>  [1725743508.1740] device (wlp2s0): supplicant interface state: completed -> authenticating
23:11:48 h5 NetworkManager[910]: <info>  [1725743508.1740] device (p2p-dev-wlp2s0): supplicant management interface state: completed -> authenticating
23:11:48 h5 wpa_supplicant[964]: wlp2s0: Trying to associate with dc:39:6f:be:99:64 (SSID='KL' freq=5220 MHz)
23:11:48 h5 NetworkManager[910]: <info>  [1725743508.2520] device (wlp2s0): supplicant interface state: authenticating -> associating
23:11:48 h5 NetworkManager[910]: <info>  [1725743508.2521] device (p2p-dev-wlp2s0): supplicant management interface state: authenticating -> associating
23:11:48 h5 kernel: wlp2s0: authenticated
23:11:48 h5 kernel: wlp2s0: associate with dc:39:6f:be:99:64 (try 1/3)
23:11:48 h5 kernel: iwlwifi 0000:02:00.0: Unhandled alg: 0x707
23:11:48 h5 kernel: wlp2s0: RX ReassocResp from dc:39:6f:be:99:64 (capab=0x1511 status=30 aid=0)
23:11:48 h5 kernel: wlp2s0: dc:39:6f:be:99:64 rejected association temporarily; comeback duration 1000 TU (1024 ms)
23:11:49 h5 kernel: wlp2s0: associate with dc:39:6f:be:99:64 (try 2/3)
23:11:49 h5 kernel: iwlwifi 0000:02:00.0: Unhandled alg: 0x707
23:11:50 h5 kernel: iwlwifi 0000:02:00.0: Not associated and the session protection is over already...
23:11:50 h5 kernel: wlp2s0: Connection to AP dc:39:6f:be:99:64 lost
23:11:50 h5 kernel: wlp2s0: associate with dc:39:6f:be:99:64 (try 3/3)
23:11:50 h5 kernel: wlp2s0: deauthenticated from dc:39:6f:be:99:64 while associating (Reason: 9=STA_REQ_ASSOC_WITHOUT_AUTH)
23:11:50 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-DISCONNECTED bssid=dc:39:6f:be:99:64 reason=9
23:11:50 h5 wpa_supplicant[964]: wlp2s0: Added BSSID dc:39:6f:be:99:64 into ignore list, ignoring for 10 seconds
23:11:50 h5 wpa_supplicant[964]: wlp2s0: BSSID dc:39:6f:be:99:64 ignore list count incremented to 2, ignoring for 10 seconds
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.4137] device (wlp2s0): supplicant interface state: associating -> disconnected
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.4138] device (p2p-dev-wlp2s0): supplicant management interface state: associating -> disconnected
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.5157] device (wlp2s0): supplicant interface state: disconnected -> scanning
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.5158] device (p2p-dev-wlp2s0): supplicant management interface state: disconnected -> scanning
23:11:50 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with e0:28:6d:6d:59:00 (SSID='KL' freq=5580 MHz)
23:11:50 h5 kernel: wlp2s0: authenticate with e0:28:6d:6d:59:00 (local address=10:91:d1:59:1a:d7)
23:11:50 h5 kernel: wlp2s0: send auth to e0:28:6d:6d:59:00 (try 1/3)
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.6930] device (wlp2s0): supplicant interface state: scanning -> authenticating
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.6931] device (p2p-dev-wlp2s0): supplicant management interface state: scanning -> authenticating
23:11:50 h5 wpa_supplicant[964]: wlp2s0: Trying to associate with e0:28:6d:6d:59:00 (SSID='KL' freq=5580 MHz)
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.7708] device (wlp2s0): supplicant interface state: authenticating -> associating
23:11:50 h5 NetworkManager[910]: <info>  [1725743510.7709] device (p2p-dev-wlp2s0): supplicant management interface state: authenticating -> associating
23:11:50 h5 kernel: wlp2s0: authenticated
23:11:50 h5 kernel: wlp2s0: associate with e0:28:6d:6d:59:00 (try 1/3)
23:11:50 h5 kernel: iwlwifi 0000:02:00.0: Unhandled alg: 0x707
23:11:50 h5 kernel: wlp2s0: RX AssocResp from e0:28:6d:6d:59:00 (capab=0x1511 status=30 aid=1266)
23:11:50 h5 kernel: wlp2s0: e0:28:6d:6d:59:00 rejected association temporarily; comeback duration 1000 TU (1024 ms)
23:11:51 h5 kernel: wlp2s0: associate with e0:28:6d:6d:59:00 (try 2/3)
23:11:52 h5 kernel: wlp2s0: associate with e0:28:6d:6d:59:00 (try 3/3)
23:11:52 h5 kmix[1635]: adding 4 mixers
23:11:52 h5 kmix[1635]: mixer "PulseAudio::Playback_Devices:1" "Wiedergabegeräte"
23:11:52 h5 kmix[1635]: PulseAudio adding 1 devices
23:11:52 h5 kmix[1635]: adding "alsa_output.pci-0000_65_00.6.HiFi__Speaker__sink" "Family 17h/19h HD Audio Controller Speaker"
23:11:52 h5 kmix[1635]: mixer "PulseAudio::Capture_Devices:1" "Aufnahmegeräte"
23:11:52 h5 kmix[1635]: PulseAudio adding 2 devices
23:11:52 h5 kmix[1635]: adding "alsa_input.pci-0000_65_00.6.HiFi__Mic2__source" "Family 17h/19h HD Audio Controller Headphones Stereo Microphone"
23:11:52 h5 kmix[1635]: adding "alsa_input.pci-0000_65_00.6.HiFi__Mic1__source" "Family 17h/19h HD Audio Controller Digital Microphone"
23:11:52 h5 kmix[1635]: mixer "PulseAudio::Playback_Streams:1" "Wiedergabestreams"
23:11:52 h5 kmix[1635]: PulseAudio adding 1 devices
23:11:52 h5 kmix[1635]: mixer "PulseAudio::Capture_Streams:1" "Aufnahmestreams"
23:11:52 h5 kmix[1635]: PulseAudio adding 0 devices
23:11:52 h5 kmix[1635]: org.kde.kmix: No such icon "audio-card-analog-pci"
23:11:52 h5 kmix[1635]: org.kde.kmix: No such icon "audio-card-analog-pci"
23:11:52 h5 kmix[1635]: org.kde.kmix: No such icon "audio-card-analog-pci"
23:11:52 h5 radioeins.sh[2817]: Das ist SMPlayer Version 24.5.0 (Revision 10277), ausgeführt auf Linux
23:11:52 h5 systemd[1062]: app-RadioEins@f680bd8a7b99476a91625cca2ac25f09.service: Consumed 34.855s CPU time, 121.7M memory peak.
23:11:53 h5 kernel: iwlwifi 0000:02:00.0: Not associated and the session protection is over already...
23:11:53 h5 kernel: wlp2s0: Connection to AP e0:28:6d:6d:59:00 lost
23:11:53 h5 kernel: wlp2s0: association with e0:28:6d:6d:59:00 timed out
23:11:53 h5 wpa_supplicant[964]: wlp2s0: Added BSSID e0:28:6d:6d:59:00 into ignore list, ignoring for 10 seconds
23:11:53 h5 wpa_supplicant[964]: wlp2s0: BSSID e0:28:6d:6d:59:00 ignore list count incremented to 2, ignoring for 10 seconds
23:11:53 h5 NetworkManager[910]: <info>  [1725743513.4450] device (wlp2s0): supplicant interface state: associating -> disconnected
23:11:53 h5 NetworkManager[910]: <info>  [1725743513.4451] device (p2p-dev-wlp2s0): supplicant management interface state: associating -> disconnected
23:11:53 h5 NetworkManager[910]: <info>  [1725743513.9389] device (wlp2s0): supplicant interface state: disconnected -> scanning
23:11:53 h5 NetworkManager[910]: <info>  [1725743513.9389] device (p2p-dev-wlp2s0): supplicant management interface state: disconnected -> scanning
23:11:54 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with dc:39:6f:be:99:65 (SSID='KL' freq=2462 MHz)
23:11:54 h5 kernel: wlp2s0: authenticate with dc:39:6f:be:99:65 (local address=10:91:d1:59:1a:d7)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.0900] device (wlp2s0): supplicant interface state: scanning -> authenticating
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.0900] device (p2p-dev-wlp2s0): supplicant management interface state: scanning -> authenticating
23:11:54 h5 kernel: wlp2s0: send auth to dc:39:6f:be:99:65 (try 1/3)
23:11:54 h5 wpa_supplicant[964]: wlp2s0: SME: Trying to authenticate with dc:39:6f:be:99:65 (SSID='KL' freq=2462 MHz)
23:11:54 h5 kernel: wlp2s0: authenticate with dc:39:6f:be:99:65 (local address=10:91:d1:59:1a:d7)
23:11:54 h5 kernel: wlp2s0: send auth to dc:39:6f:be:99:65 (try 1/3)
23:11:54 h5 wpa_supplicant[964]: wlp2s0: PMKSA-CACHE-ADDED dc:39:6f:be:99:65 0
23:11:54 h5 wpa_supplicant[964]: wlp2s0: Trying to associate with dc:39:6f:be:99:65 (SSID='KL' freq=2462 MHz)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.2436] device (wlp2s0): supplicant interface state: authenticating -> associating
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.2436] device (p2p-dev-wlp2s0): supplicant management interface state: authenticating -> associating
23:11:54 h5 kernel: wlp2s0: authenticated
23:11:54 h5 kernel: wlp2s0: associate with dc:39:6f:be:99:65 (try 1/3)
23:11:54 h5 kernel: wlp2s0: RX AssocResp from dc:39:6f:be:99:65 (capab=0x1431 status=0 aid=2)
23:11:54 h5 wpa_supplicant[964]: wlp2s0: Associated with dc:39:6f:be:99:65
23:11:54 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
23:11:54 h5 kernel: wlp2s0: associated
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.2953] device (wlp2s0): supplicant interface state: associating -> 4way_handshake
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.2954] device (p2p-dev-wlp2s0): supplicant management interface state: associating -> 4way_handshake
23:11:54 h5 kernel: wlp2s0: Limiting TX power to 20 (20 - 0) dBm as advertised by dc:39:6f:be:99:65
23:11:54 h5 wpa_supplicant[964]: wlp2s0: WPA: Key negotiation completed with dc:39:6f:be:99:65 [PTK=CCMP GTK=CCMP]
23:11:54 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-CONNECTED - Connection to dc:39:6f:be:99:65 completed [id=0 id_str=]
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5131] device (wlp2s0): supplicant interface state: 4way_handshake -> completed
23:11:54 h5 wpa_supplicant[964]: wlp2s0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-44 noise=9999 txrate=1000
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5185] device (wlp2s0): ip:dhcp4: restarting
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5185] dhcp4 (wlp2s0): canceled DHCP transaction
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5185] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5186] dhcp4 (wlp2s0): state changed no lease
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5186] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5187] device (wlp2s0): ip:dhcp6: restarting
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5188] dhcp6 (wlp2s0): canceled DHCP transaction
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5188] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5188] dhcp6 (wlp2s0): state changed no lease
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5189] dhcp6 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5190] device (p2p-dev-wlp2s0): supplicant management interface state: 4way_handshake -> completed
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5564] dhcp6 (wlp2s0): state changed new lease, address=2a02:908:69c:8040:86d2:c07b:c543:4585
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5581] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112, acd pending
23:11:54 h5 NetworkManager[910]: <info>  [1725743514.5583] dhcp4 (wlp2s0): state changed new lease, address=192.168.212.112
23:11:54 h5 systemd[1]: Starting Network Manager Script Dispatcher Service...
23:11:54 h5 systemd[1]: Started Network Manager Script Dispatcher Service.
23:12:04 h5 systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
23:12:19 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:12:19 h5 rtkit-daemon[1138]: Supervising 8 threads of 5 processes of 1 users.
23:12:23 h5 plasmashell[1317]: The cached device pixel ratio value was stale on window update.  Please file a QTBUG which explains how to reproduce.
23:12:24 h5 NetworkManager[910]: <info>  [1725743544.2939] audit: op="statistics" interface="wlp2s0" ifindex=2 args="2000" pid=1317 uid=1000 result="success"
23:12:24 h5 NetworkManager[910]: <info>  [1725743544.2974] audit: op="statistics" interface="wlp2s0" ifindex=2 args="500" pid=1454 uid=1000 result="success"
23:12:24 h5 plasmashell[1317]: qrc:/qt/qml/org/kde/plasma/components/ScrollView.qml:53:29: QML ScrollBar: Binding loop detected for property "visible"

The Network itself is reconnecting, but for participating in video conferences the breakdown is inacceptable ..

Anyone here with an idea, what is going on here and how to fix?

Thanks,
Peer

Last edited by PeerK (2024-09-07 22:37:04)

Strike0 · 2024-09-13 20:00:32

Your interpretation of the log seems right, the laptop disconnects from one mesh-AP and takes quite a bit to obtain a new lease from the other (timestamp 23:11:48). One reason can also be temporary congestion (neighbour starts to stream).

The simple way to work-around this would be to make a wifi-profile which is fixed to one AP via its BSSID. Have a look at the two methods referred to in https://wiki.archlinux.org/title/Networ … s#Cause_#8
Assuming you're stationary when video conferencing, this may fix it because you can choose the strongest signal AP to bind the connection to. However, the roaming profile should obviously)not be set to autoconnect in this case.

The complex way would be to figure the Fritz mesh settings first. Perhaps increase dhcp lease times and ascertain mesh options. For a home network have a look whether you can explicitly enable "802.11r Roaming fast-transition" somewhere and do it for all mesh points.

Arch Linux

#1 2024-09-07 22:18:40

WiFi-Issue: Regularily disconnecting, due to Mesh? CTRL-EVENT-SUBNET-S

#2 2024-09-13 20:00:32

Re: WiFi-Issue: Regularily disconnecting, due to Mesh? CTRL-EVENT-SUBNET-S

Board footer