Wifi connection disconnect reconnect after resume

hans · 20 October 2023 14:11

After resume from sleep Wifi will be disconnected after a few seconds and is then reconnected. The log shows (probably) what is happening, but I do not have the skills to understand. With each kernel update the reconnect time seems to grow.

relevant inxi:

System:
  Kernel: 6.1.55-1-MANJARO arch: x86_64 bits: 64 compiler: gcc v: 13.2.1
    clocksource: tsc available: acpi_pm
    parameters: BOOT_IMAGE=/boot/vmlinuz-6.1-x86_64
    root=UUID=adcda0b2-d3e3-4d08-a9bd-802191d2faf3 ro efi=runtime nowatchdog
    quiet apparmor=1 security=apparmor udev.log_priority=3
  Desktop: KDE Plasma v: 5.27.8 tk: Qt v: 5.15.11 wm: kwin_wayland vt: 1
    dm: SDDM Distro: Manjaro Linux base: Arch Linux
Graphics:
  Device-1: Intel CoffeeLake-S GT2 [UHD Graphics 630] vendor: ASUSTeK
    driver: i915 v: kernel arch: Gen-9.5 process: Intel 14nm built: 2016-20
    ports: active: DP-2 empty: DP-1, DP-3, HDMI-A-1, HDMI-A-2, HDMI-A-3
    bus-ID: 00:02.0 chip-ID: 8086:3e91 class-ID: 0300
  Display: wayland server: X.org v: 1.21.1.8 with: Xwayland v: 23.2.1
    compositor: kwin_wayland driver: X: loaded: modesetting alternate: fbdev,vesa
    dri: iris gpu: i915 display-ID: 0
  Monitor-1: DP-2 res: 1920x1080 size: N/A modes: N/A
  
  Network:
  Device-1: Intel Ethernet I219-V vendor: ASUSTeK driver: e1000e v: kernel
    port: N/A bus-ID: 00:1f.6 chip-ID: 8086:15bc class-ID: 0200
  IF: eno1 state: down mac: <filter>
  Device-2: TP-Link Archer T3U [Realtek RTL8812BU] driver: rtl88x2bu
    type: USB rev: 2.1 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 1-11:8
    chip-ID: 2357:012d class-ID: 0000 serial: <filter>
  IF: wlp0s20f0u11 state: up mac: <filter>
  IP v4: <filter> type: dynamic noprefixroute scope: global
    broadcast: <filter>
  IP v6: <filter> type: dynamic noprefixroute scope: global
  IP v6: <filter> type: dynamic noprefixroute scope: global
  IP v6: <filter> type: noprefixroute scope: link
  WAN IP: <filter>
Bluetooth:
  Message: No bluetooth data found.
Logical:
  Message: No logical block device data found.
RAID:
  Message: No RAID data found.
Drives:
  Local Storage: total
USB
  Device-3: 1-11:8 info: TP-Link Archer T3U [Realtek RTL8812BU] type: Network
    driver: rtl88x2bu interfaces: 1 rev: 2.1 speed: 480 Mb/s (57.2 MiB/s)
    lanes: 1 mode: 2.0 power: 500mA chip-ID: 2357:012d class-ID: 0000
    serial: <filter>

The journald log file shows a.o. (hopefully enough data)

20-10-2023 11:48	kernel	RTW:  suspend start

20-10-2023 11:48	kernel	RTW: rtw_suspend_normal: ### ERROR #### driver in IPS ####ERROR###!!!
20-10-2023 11:48	kernel	RTW: rtw_dev_unload: driver in IPS-FWLPS
20-10-2023 11:48	kernel	e1000e: EEE TX LPI TIMER: 00000011
20-10-2023 11:48	kernel	RTW: rtw suspend success in 0 ms
20-10-2023 11:48	kernel	sd 4:0:0:0: [sda] Synchronizing SCSI cache
20-10-2023 11:48	kernel	sd 4:0:0:0: [sda] Stopping disk
20-10-2023 11:48	kernel	ACPI: PM: Preparing to enter system sleep state S3

20-10-2023 11:48	kernel	ACPI: PM: Saving platform NVS memory
20-10-2023 11:48	kernel	Disabling non-boot CPUs ...
20-10-2023 11:48	kernel	smpboot: CPU 1 is now offline
20-10-2023 11:48	kernel	smpboot: CPU 2 is now offline
20-10-2023 11:48	kernel	smpboot: CPU 3 is now offline

20-10-2023 11:48	kernel	ACPI: PM: Low-level resume complete
20-10-2023 11:48	kernel	ACPI: PM: Restoring platform NVS memory
20-10-2023 11:48	kernel	Enabling non-boot CPUs ...
20-10-2023 11:48	kernel	x86: Booting SMP configuration:
20-10-2023 11:48	kernel	smpboot: Booting Node 0 Processor 1 APIC 0x2
20-10-2023 11:48	kernel	CPU1 is up
20-10-2023 11:48	kernel	smpboot: Booting Node 0 Processor 2 APIC 0x4
20-10-2023 11:48	kernel	CPU2 is up
20-10-2023 11:48	kernel	smpboot: Booting Node 0 Processor 3 APIC 0x6
20-10-2023 11:48	kernel	CPU3 is up
20-10-2023 11:48	kernel	ACPI: PM: Waking up from system sleep state S3
20-10-2023 11:48	kernel	sd 4:0:0:0: [sda] Starting disk
20-10-2023 11:48	kernel	i915 0000:00:02.0: [drm] [ENCODER:94:DDI B/PHY B] is disabled/in DSI mode with an ungated DDI clock, gate it
20-10-2023 11:48	kernel	i915 0000:00:02.0: [drm] [ENCODER:111:DDI C/PHY C] is disabled/in DSI mode with an ungated DDI clock, gate it
20-10-2023 11:48	kernel	i915 0000:00:02.0: [drm] [ENCODER:121:DDI D/PHY D] is disabled/in DSI mode with an ungated DDI clock, gate it
20-10-2023 11:48	kernel	i915 0000:00:02.0: [drm] [ENCODER:125:DDI E/PHY E] is disabled/in DSI mode with an ungated DDI clock, gate it
20-10-2023 11:48	kernel	nvme nvme0: Shutdown timeout set to 8 seconds
20-10-2023 11:48	kernel	nvme nvme0: 4/0/0 default/read/poll queues
20-10-2023 11:48	kernel	RTW: resume start

20-10-2023 11:48	kernel	RTW: [HALMAC][ALWAYS]shall R reg twice!!

20-10-2023 11:48	kernel	OOM killer enabled.
20-10-2023 11:48	kernel	Restarting tasks ... 
20-10-2023 11:48	kernel	mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
20-10-2023 11:48	kernel	pcieport 0000:00:1b.0: PCI bridge to [bus 01]
20-10-2023 11:48	kernel	pcieport 0000:00:1b.0:   bridge window [mem 0xa1100000-0xa11fffff]
20-10-2023 11:48	kwin_wayland	kwin_libinput: Libinput: client bug: timer event7 debounce: scheduled expiry is in the past (-2909ms), your system is too slow
20-10-2023 11:48	kwin_wayland	kwin_libinput: Libinput: client bug: timer event7 debounce: scheduled expiry is in the past (-2902ms), your system is too slow
20-10-2023 11:48	systemd-sleep	System returned from sleep state.
20-10-2023 11:48	kernel	done.
20-10-2023 11:48	kernel	random: crng reseeded on system resumption
20-10-2023 11:48	kernel	PM: suspend exit
20-10-2023 11:48	systemd	systemd-suspend.service: Deactivated successfully.
20-10-2023 11:48	systemd	Finished System Suspend.
20-10-2023 11:48	systemd	Stopped target Sleep.
20-10-2023 11:48	systemd	Reached target Suspend.
20-10-2023 11:48	systemd	Stopped target Suspend.
20-10-2023 11:48	systemd-logind	Operation 'sleep' finished.

20-10-2023 11:48	NetworkManager	<info>  [1697795336.3576] manager: sleep: wake requested (sleeping: yes  enabled: yes)
20-10-2023 11:48	NetworkManager	<info>  [1697795336.3576] device (eno1): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
20-10-2023 11:48	NetworkManager	<info>  [1697795336.4384] device (eno1): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
20-10-2023 11:48	kernel	e1000e 0000:00:1f.6 eno1: NIC Link is Down
20-10-2023 11:48	NetworkManager	<info>  [1697795336.6269] device (p2p-dev-wlp0s20f0u11): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
20-10-2023 11:48	NetworkManager	<info>  [1697795336.6270] manager: NetworkManager state is now DISCONNECTING
20-10-2023 11:48	systemd	NetworkManager-dispatcher.service: Deactivated successfully.
20-10-2023 11:49	rtkit-daemon	Supervising 0 threads of 0 processes of 0 users.
20-10-2023 11:49	rtkit-daemon	Supervising 0 threads of 0 processes of 0 users.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7750] device (wlp0s20f0u11): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
20-10-2023 11:49	dbus-daemon	[system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.4' (uid=0 pid=587 comm="/usr/bin/NetworkManager --no-daemon")
20-10-2023 11:49	avahi-daemon	Withdrawing address record for fd4c:4b32:3230:0:a16:2ffc:d752:62d on wlp0s20f0u11.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7758] dhcp4 (wlp0s20f0u11): canceled DHCP transaction
20-10-2023 11:49	avahi-daemon	Withdrawing address record for 2a02:a443:c74f:0:aae4:9e96:4888:9307 on wlp0s20f0u11.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7759] dhcp4 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
20-10-2023 11:49	avahi-daemon	Leaving mDNS multicast group on interface wlp0s20f0u11.IPv6 with address 2a02:a443:c74f:0:aae4:9e96:4888:9307.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7759] dhcp4 (wlp0s20f0u11): state changed no lease
20-10-2023 11:49	avahi-daemon	Joining mDNS multicast group on interface wlp0s20f0u11.IPv6 with address fe80::a7be:6d32:2e4d:3399.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7760] dhcp6 (wlp0s20f0u11): canceled DHCP transaction
20-10-2023 11:49	avahi-daemon	Registering new address record for fe80::a7be:6d32:2e4d:3399 on wlp0s20f0u11.*.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7760] dhcp6 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
20-10-2023 11:49	avahi-daemon	Withdrawing address record for fe80::a7be:6d32:2e4d:3399 on wlp0s20f0u11.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7760] dhcp6 (wlp0s20f0u11): state changed no lease
20-10-2023 11:49	avahi-daemon	Leaving mDNS multicast group on interface wlp0s20f0u11.IPv6 with address fe80::a7be:6d32:2e4d:3399.
20-10-2023 11:49	avahi-daemon	Interface wlp0s20f0u11.IPv6 no longer relevant for mDNS.
20-10-2023 11:49	avahi-daemon	Interface wlp0s20f0u11.IPv4 no longer relevant for mDNS.
20-10-2023 11:49	avahi-daemon	Leaving mDNS multicast group on interface wlp0s20f0u11.IPv4 with address 192.168.2.126.
20-10-2023 11:49	avahi-daemon	Withdrawing address record for 192.168.2.126 on wlp0s20f0u11.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.7769] device (wlp0s20f0u11): set-hw-addr: set MAC address to 96:B1:8F:D6:AB:1D (scanning)
20-10-2023 11:49	avahi-daemon	Joining mDNS multicast group on interface wlp0s20f0u11.IPv4 with address 192.168.2.126.
20-10-2023 11:49	avahi-daemon	New relevant interface wlp0s20f0u11.IPv4 for mDNS.
20-10-2023 11:49	avahi-daemon	Registering new address record for 192.168.2.126 on wlp0s20f0u11.IPv4.
20-10-2023 11:49	avahi-daemon	Withdrawing address record for 192.168.2.126 on wlp0s20f0u11.
20-10-2023 11:49	avahi-daemon	Leaving mDNS multicast group on interface wlp0s20f0u11.IPv4 with address 192.168.2.126.
20-10-2023 11:49	avahi-daemon	Interface wlp0s20f0u11.IPv4 no longer relevant for mDNS.
20-10-2023 11:49	systemd	Starting Network Manager Script Dispatcher Service...
20-10-2023 11:49	dbus-daemon	[system] Successfully activated service 'org.freedesktop.nm_dispatcher'
20-10-2023 11:49	systemd	Started Network Manager Script Dispatcher Service.
20-10-2023 11:49	NetworkManager	<info>  [1697795346.8235] manager: NetworkManager state is now DISCONNECTED
20-10-2023 11:49	plasmashell	Could not find the Plasmoid for Plasma::FrameSvgItem(0x560cf44dd4f0) QQmlContext(0x560cf2001660) QUrl("file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml")
20-10-2023 11:49	plasmashell	Could not find the Plasmoid for Plasma::FrameSvgItem(0x560cf44dd4f0) QQmlContext(0x560cf2001660) QUrl("file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml")
20-10-2023 11:49	kernel	start_addr=(0x20000), end_addr=(0x40000), buffer_size=(0x20000), smp_number_max=(16384)
20-10-2023 11:49	kernel	RTW: ERROR rtw_halmac_led_cfg: pinmux set fail!(0x64)
20-10-2023 11:49	kernel	RTW: nolinked power save leave
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: Reject scan trigger since one is already pending
20-10-2023 11:49	nmbd	[2023/10/20 11:49:08.015222,  0] ../../source3/libsmb/nmblib.c:923(send_udp)
20-10-2023 11:49	nmbd	  Packet send failed to 192.168.2.255(138) ERRNO=Network is unreachable
20-10-2023 11:49	nmbd	[2023/10/20 11:49:10.017461,  0] ../../source3/libsmb/nmblib.c:923(send_udp)
20-10-2023 11:49	nmbd	  Packet send failed to 192.168.2.255(138) ERRNO=Network is unreachable
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1092] policy: auto-activating connection 'Arjan' (6d830b65-5c84-4954-a550-41824f99e07f)
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1094] device (wlp0s20f0u11): Activation: starting connection 'Arjan' (6d830b65-5c84-4954-a550-41824f99e07f)
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1095] device (wlp0s20f0u11): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1096] manager: NetworkManager state is now CONNECTING
20-10-2023 11:49	kernel	RTW: nolinked power save enter
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1203] device (wlp0s20f0u11): set-hw-addr: reset MAC address to 30:DE:4B:84:A8:CF (preserve)
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1204] device (wlp0s20f0u11): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1206] device (wlp0s20f0u11): Activation: (wifi) access point 'Arjan' has security, but secrets are required.
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1206] device (wlp0s20f0u11): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1207] sup-iface[f3a425310db561a3,1,wlp0s20f0u11]: wps: type pbc start...
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1332] device (wlp0s20f0u11): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	kded5	kf.networkmanagerqt: void NetworkManager::ConnectionPrivate::onPropertiesChanged(const QVariantMap&) Unhandled property "VersionId"
20-10-2023 11:49	plasmashell	kf.networkmanagerqt: void NetworkManager::ConnectionPrivate::onPropertiesChanged(const QVariantMap&) Unhandled property "VersionId"
20-10-2023 11:49	sayonara	"Object does not exist at path “/org/freedesktop/NetworkManager/ActiveConnection/9”"
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1341] device (wlp0s20f0u11): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] device (wlp0s20f0u11): Activation: (wifi) connection 'Arjan' has security, and secrets exist.  No new secrets needed.
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'ssid' value 'Arjan'
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'scan_ssid' value '1'
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'freq_list' value '5035 5040 5045 5055 5060 5080 5170 5180 5190 5200 5210 5220 5230 5240 5250 5260 5280 5290 5300 5320 5500 5520 5540 5560 5580 5600 5620 5640 5660 5680 5700 5745 5760 5765 5785 5800 5805 5825 4915 4920 4925 4935 4945 4960 4980'
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'bgscan' value 'simple:30:-65:300'
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK'
20-10-2023 11:49	NetworkManager	<info>  [1697795351.1343] Config: added 'psk' value '<hidden>'
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: WPS-CANCEL
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: Trying to associate with c8:d1:2a:15:75:a0 (SSID='Arjan' freq=5500 MHz)
20-10-2023 11:49	kernel	RTW: [HALMAC][ALWAYS]shall R reg twice!!
20-10-2023 11:49	kernel	start_addr=(0x20000), end_addr=(0x40000), buffer_size=(0x20000), smp_number_max=(16384)
20-10-2023 11:49	NetworkManager	<info>  [1697795351.8027] device (wlp0s20f0u11): supplicant interface state: disconnected -> associating
20-10-2023 11:49	kernel	RTW: nolinked power save leave
20-10-2023 11:49	kernel	RTW: rtw_set_802_11_connect(wlp0s20f0u11)  fw_state=0x00000008
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: CTRL-EVENT-STARTED-CHANNEL-SWITCH freq=5500 ht_enabled=1 ch_offset=1 ch_width=80 MHz cf1=5530 cf2=0
20-10-2023 11:49	kernel	RTW: start auth
20-10-2023 11:49	kernel	RTW: auth success, start assoc
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: Associated with c8:d1:2a:15:75:a0
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
20-10-2023 11:49	kernel	RTW: assoc success
20-10-2023 11:49	kernel	RTW: ============ STA [c8:d1:2a:15:75:a0]  ===================
20-10-2023 11:49	kernel	RTW: mac_id : 0
20-10-2023 11:49	kernel	RTW: wireless_mode : 0x44
20-10-2023 11:49	kernel	RTW: mimo_type : 2
20-10-2023 11:49	kernel	RTW: static smps : N
20-10-2023 11:49	kernel	RTW: bw_mode : 80MHz, ra_bw_mode : 80MHz
20-10-2023 11:49	kernel	RTW: rate_id : 9
20-10-2023 11:49	kernel	RTW: rssi : -1 (%), rssi_level : 0
20-10-2023 11:49	kernel	RTW: is_support_sgi : Y, is_vht_enable : Y
20-10-2023 11:49	kernel	RTW: disable_ra : N, disable_pt : N
20-10-2023 11:49	kernel	RTW: is_noisy : N
20-10-2023 11:49	kernel	RTW: txrx_state : 0
20-10-2023 11:49	kernel	RTW: curr_tx_rate : CCK_1M (L)
20-10-2023 11:49	kernel	RTW: curr_tx_bw : 20MHz
20-10-2023 11:49	kernel	RTW: curr_retry_ratio : 0
20-10-2023 11:49	kernel	RTW: ra_mask : 0x00000000fffffff0

20-10-2023 11:49	NetworkManager	<info>  [1697795352.0031] device (wlp0s20f0u11): supplicant interface state: associating -> associated
20-10-2023 11:49	kernel	RTW: rtw_aes_decrypt(wlp0s20f0u11) no_gkey_bc_cnt:1, no_gkey_mc_cnt:0
20-10-2023 11:49	kernel	RTW: recv eapol packet 1/4
20-10-2023 11:49	kernel	RTW: send eapol packet 2/4
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: WPA: Key negotiation completed with c8:d1:2a:15:75:a0 [PTK=CCMP GTK=CCMP]
20-10-2023 11:49	wpa_supplicant	wlp0s20f0u11: CTRL-EVENT-CONNECTED - Connection to c8:d1:2a:15:75:a0 completed [id=0 id_str=]
20-10-2023 11:49	wpa_supplicant	bgscan simple: Failed to enable signal strength monitoring
20-10-2023 11:49	kernel	RTW: recv eapol packet 3/4
20-10-2023 11:49	kernel	RTW: send eapol packet 4/4
20-10-2023 11:49	kernel	RTW: set pairwise key camid:0, addr:c8:d1:2a:15:75:a0, kid:0, type:AES
20-10-2023 11:49	kernel	IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f0u11: link becomes ready
20-10-2023 11:49	kernel	RTW: set group key camid:1, addr:c8:d1:2a:15:75:a0, kid:1, type:AES
20-10-2023 11:49	avahi-daemon	Joining mDNS multicast group on interface wlp0s20f0u11.IPv6 with address fe80::a7be:6d32:2e4d:3399.
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7374] device (wlp0s20f0u11): supplicant interface state: associated -> completed
20-10-2023 11:49	avahi-daemon	New relevant interface wlp0s20f0u11.IPv6 for mDNS.
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7374] device (wlp0s20f0u11): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Arjan"
20-10-2023 11:49	avahi-daemon	Registering new address record for fe80::a7be:6d32:2e4d:3399 on wlp0s20f0u11.*.
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7375] device (wlp0s20f0u11): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7377] dhcp4 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7495] dhcp4 (wlp0s20f0u11): state changed new lease, address=192.168.2.126
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7497] policy: set 'Arjan' (wlp0s20f0u11) as default for IPv4 routing and DNS
20-10-2023 11:49	avahi-daemon	Joining mDNS multicast group on interface wlp0s20f0u11.IPv4 with address 192.168.2.126.
20-10-2023 11:49	avahi-daemon	New relevant interface wlp0s20f0u11.IPv4 for mDNS.
20-10-2023 11:49	avahi-daemon	Registering new address record for 192.168.2.126 on wlp0s20f0u11.IPv4.
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7604] device (wlp0s20f0u11): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7637] device (wlp0s20f0u11): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7639] device (wlp0s20f0u11): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7641] manager: NetworkManager state is now CONNECTED_SITE
20-10-2023 11:49	NetworkManager	<info>  [1697795352.7643] device (wlp0s20f0u11): Activation: successful, device activated.
20-10-2023 11:49	plasmashell	Could not find the Plasmoid for Plasma::FrameSvgItem(0x560cf0b15920) QQmlContext(0x560cf2001660) QUrl("file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml")
20-10-2023 11:49	plasmashell	Could not find the Plasmoid for Plasma::FrameSvgItem(0x560cf0b15920) QQmlContext(0x560cf2001660) QUrl("file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml")
20-10-2023 11:49	NetworkManager	<info>  [1697795353.8043] manager: NetworkManager state is now CONNECTED_GLOBAL
20-10-2023 11:49	NetworkManager	<info>  [1697795354.5559] dhcp6 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
20-10-2023 11:49	NetworkManager	<info>  [1697795354.5563] policy: set 'Arjan' (wlp0s20f0u11) as default for IPv6 routing and DNS
20-10-2023 11:49	avahi-daemon	Leaving mDNS multicast group on interface wlp0s20f0u11.IPv6 with address fe80::a7be:6d32:2e4d:3399.
20-10-2023 11:49	avahi-daemon	Joining mDNS multicast group on interface wlp0s20f0u11.IPv6 with address 2a02:a443:c74f:0:aae4:9e96:4888:9307.
20-10-2023 11:49	avahi-daemon	Registering new address record for 2a02:a443:c74f:0:aae4:9e96:4888:9307 on wlp0s20f0u11.*.
20-10-2023 11:49	avahi-daemon	Withdrawing address record for fe80::a7be:6d32:2e4d:3399 on wlp0s20f0u11.
20-10-2023 11:49	avahi-daemon	Registering new address record for fd4c:4b32:3230:0:a16:2ffc:d752:62d on wlp0s20f0u11.*.
20-10-2023 11:49	NetworkManager	<info>  [1697795354.5679] dhcp6 (wlp0s20f0u11): state changed new lease
20-10-2023 11:49	systemd	NetworkManager-dispatcher.service: Deactivated successfully.

The wifi driver (github RinCat) is installed via dkms:

dkms status
rtl88x2bu/5.13.1.r189.12cfcd8, 5.15.133-1-MANJARO, x86_64: installed
rtl88x2bu/5.13.1.r189.12cfcd8, 6.1.55-1-MANJARO, x86_64: installed
vboxhost/7.0.10_OSE, 5.15.133-1-MANJARO, x86_64: installed
vboxhost/7.0.10_OSE, 6.1.55-1-MANJARO, x86_64: installed

Thanks very much for advice / tips / links how to solve this issue.

soundofthunder · 20 October 2023 16:26

I’m not sure this is actually an issue that needs to be solved.
The WiFi is simply re-initializing after sleep.

Think of it in terms of a yawn, and a stretch, in the mornings; after sleep.

Cheers.

hans · 20 October 2023 18:07

Very relaxed answer! This ‘yawn’ takes about 5 - 7 seconds, lazy computer! and it was not here previously. After waking up, 5 seconds later KDE Networks (in the tray) reports first ‘disconnected’ and then a few seconds later ‘connected’. Probably since the last stable update.
I have Timeshift snapshots, maybe go back in time and try that?!?

soundofthunder · 20 October 2023 21:15

Perhaps the computer could fall to a standby mode instead of hibernation:

S3, or Standby, or sometimes called Suspend to RAM (STR):
– The CPU, and PS/U remain powered off while RAM remains powered on.

hans · 23 October 2023 15:25

I have rolled back to the state of Oct 03, that is, before the last stable updates. The issue with the connect / disconnect / connect sequence were gone. After applying again the stable updates the issue is back again. I have zoomed into Networkmanager in the log and copied below what I think is happening. Again, help / tips how to solve this are appreciated.

What I think I see is:

the first log line is just after Resume from S3 state has started
there are a lot disconnect / connect which I do not understand
it takes 14 seconds before wifi is available, from 10:34:56 … 10:35.11

maandag 23 oktober 2023 10:34:56 CEST	NetworkManager	<info>  [1698050096.4273] manager: sleep: wake requested (sleeping: yes  enabled: yes)
maandag 23 oktober 2023 10:34:56 CEST	NetworkManager	<info>  [1698050096.4273] device (eno1): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:34:56 CEST	NetworkManager	<info>  [1698050096.5077] device (eno1): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
maandag 23 oktober 2023 10:34:56 CEST	NetworkManager	<info>  [1698050096.6953] device (p2p-dev-wlp0s20f0u11): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
maandag 23 oktober 2023 10:34:56 CEST	NetworkManager	<info>  [1698050096.6955] manager: NetworkManager state is now DISCONNECTING
maandag 23 oktober 2023 10:34:57 CEST	systemd	NetworkManager-dispatcher.service: Deactivated successfully.
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9730] device (wlp0s20f0u11): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:06 CEST	dbus-daemon	[system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.4' (uid=0 pid=741 comm="/usr/bin/NetworkManager --no-daemon")
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9743] dhcp4 (wlp0s20f0u11): canceled DHCP transaction
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9743] dhcp4 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9743] dhcp4 (wlp0s20f0u11): state changed no lease
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9745] dhcp6 (wlp0s20f0u11): canceled DHCP transaction
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9745] dhcp6 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9745] dhcp6 (wlp0s20f0u11): state changed no lease
maandag 23 oktober 2023 10:35:06 CEST	NetworkManager	<info>  [1698050106.9760] device (wlp0s20f0u11): set-hw-addr: set MAC address to 5E:BD:0B:D0:BD:A8 (scanning)
maandag 23 oktober 2023 10:35:06 CEST	systemd	Starting Network Manager Script Dispatcher Service...
maandag 23 oktober 2023 10:35:07 CEST	systemd	Started Network Manager Script Dispatcher Service.
maandag 23 oktober 2023 10:35:07 CEST	NetworkManager	<info>  [1698050107.0255] manager: NetworkManager state is now DISCONNECTED
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3383] policy: auto-activating connection 'Arjan' (6d830b65-5c84-4954-a550-41824f99e07f)
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3387] device (wlp0s20f0u11): Activation: starting connection 'Arjan' (6d830b65-5c84-4954-a550-41824f99e07f)
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3388] device (wlp0s20f0u11): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3389] manager: NetworkManager state is now CONNECTING
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3458] device (wlp0s20f0u11): set-hw-addr: reset MAC address to 30:DE:4B:84:A8:CF (preserve)
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3459] device (wlp0s20f0u11): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3461] device (wlp0s20f0u11): Activation: (wifi) access point 'Arjan' has security, but secrets are required.
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3461] device (wlp0s20f0u11): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3462] sup-iface[5e66cfd85d02d963,0,wlp0s20f0u11]: wps: type pbc start...
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3469] device (wlp0s20f0u11): supplicant interface state: disconnected -> interface_disabled
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3586] device (wlp0s20f0u11): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:11 CEST	plasmashell	kf.networkmanagerqt: void NetworkManager::ConnectionPrivate::onPropertiesChanged(const QVariantMap&) Unhandled property "VersionId"
maandag 23 oktober 2023 10:35:11 CEST	kded5	kf.networkmanagerqt: void NetworkManager::ConnectionPrivate::onPropertiesChanged(const QVariantMap&) Unhandled property "VersionId"
maandag 23 oktober 2023 10:35:11 CEST	kdeconnectd	"Object does not exist at path “/org/freedesktop/NetworkManager/ActiveConnection/2”"
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3593] device (wlp0s20f0u11): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] device (wlp0s20f0u11): Activation: (wifi) connection 'Arjan' has security, and secrets exist.  No new secrets needed.
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] Config: added 'ssid' value 'Arjan'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] Config: added 'scan_ssid' value '1'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] Config: added 'freq_list' value '5035 5040 5045 5055 5060 5080 5170 5180 5190 5200 5210 5220 5230 5240 5250 5260 5280 5290 5300 5320 5500 5520 5540 5560 5580 5600 5620 5640 5660 5680 5700 5745 5760 5765 5785 5800 5805 5825 4915 4920 4925 4935 4945 4960 4980'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] Config: added 'bgscan' value 'simple:30:-65:300'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3594] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3595] Config: added 'psk' value '<hidden>'
maandag 23 oktober 2023 10:35:11 CEST	NetworkManager	<info>  [1698050111.3922] device (wlp0s20f0u11): supplicant interface state: interface_disabled -> disconnected
maandag 23 oktober 2023 10:35:12 CEST	NetworkManager	<info>  [1698050112.0546] device (wlp0s20f0u11): supplicant interface state: disconnected -> associating
maandag 23 oktober 2023 10:35:12 CEST	NetworkManager	<info>  [1698050112.3339] device (wlp0s20f0u11): supplicant interface state: associating -> associated
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2359] device (wlp0s20f0u11): supplicant interface state: associated -> completed
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2359] device (wlp0s20f0u11): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Arjan"
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2360] device (wlp0s20f0u11): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2363] dhcp4 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2456] dhcp4 (wlp0s20f0u11): state changed new lease, address=192.168.2.126
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2458] policy: set 'Arjan' (wlp0s20f0u11) as default for IPv4 routing and DNS
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2606] device (wlp0s20f0u11): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2635] device (wlp0s20f0u11): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2636] device (wlp0s20f0u11): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2638] manager: NetworkManager state is now CONNECTED_SITE
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.2641] device (wlp0s20f0u11): Activation: successful, device activated.
maandag 23 oktober 2023 10:35:13 CEST	NetworkManager	<info>  [1698050113.3431] manager: NetworkManager state is now CONNECTED_GLOBAL
maandag 23 oktober 2023 10:35:14 CEST	NetworkManager	<info>  [1698050114.6821] dhcp6 (wlp0s20f0u11): activation: beginning transaction (timeout in 45 seconds)
maandag 23 oktober 2023 10:35:14 CEST	NetworkManager	<info>  [1698050114.6825] policy: set 'Arjan' (wlp0s20f0u11) as default for IPv6 routing and DNS
maandag 23 oktober 2023 10:35:14 CEST	NetworkManager	<info>  [1698050114.7078] dhcp6 (wlp0s20f0u11): state changed new lease
maandag 23 oktober 2023 10:35:17 CEST	systemd	NetworkManager-dispatcher.service: Deactivated successfully.

soundofthunder · 23 October 2023 15:55

You might be able to glean something useful from other peoples woes:

Cheers.

hans · 23 October 2023 18:38

Thanks. The first link helped to reduce the connect time after resume; the “disconnect connects” are gone, it seems.

I followed the advice in the post of Nachlese.

added on Nov 8, 2023: This was not the solution as it turned out. The stable update of Nov 6 solved it finally without any intervention from me. As I experienced with some other ‘hard to diagnose’ issues: just wait for the next stable update.

system · 26 October 2023 08:39

This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.