search

RinCat / RTL88x2BU-Linux-Driver

Realtek RTL88x2BU WiFi USB Driver for Linux
GNU General Public License v2.0
1.26k stars 197 forks source link

Linux kernel 5.18 loss of internet after connecting #141

Open giovanniPepi opened 2 years ago

giovanniPepi commented 2 years ago

Hi @RinCat, thanks for the amazing support on this driver

After upgrading to 5.18, the adapter is able to establish a connection and get internet for a few seconds, then internet is lost although still conected and scanning networks. This problem started right after upgrading to 5.18 and rebuilding the module.

I've tried manually building and then installing the AUR package, both seem to result in the same behavior, which mainly seems to be this final error:

wpa_supplicant[1232]: wlan0: CTRL-EVENT-BEACON-LOSS

Furthermore, the adapter isn't accepting commands anymore:

sudo iw wlan0 set txpower fixed 50

command failed: Operation not supported (-95)

kernel output when connecting and getting disconnected: 

OS: Arch Linux x86_64 
Kernel: 5.18.0-zen1-1-zen 


May 29 10:05:14 hostname NetworkManager[1047]: <info>  [1653829514.7566] policy: auto-activating connection 'Wifi name' (cb6dcd2-edfa-492b-a2dc-1354f967ab3e)
May 29 10:05:14 hostname NetworkManager[1047]: <info>  [1653829514.7570] device (wlan0): Activation: starting connection 'Wifi name' (cb6dcd2-edfa-492b-a2dc-1354f967ab3e)
May 29 10:05:14 hostname NetworkManager[1047]: <info>  [1653829514.7570] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
May 29 10:05:14 hostname NetworkManager[1047]: <info>  [1653829514.7573] manager: NetworkManager state is now CONNECTING
May 29 10:05:14 hostname NetworkManager[1047]: <info>  [1653829514.7944] device (wlan0): set-hw-addr: reset MAC address to (preserve)
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2902] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2905] device (wlan0): Activation: (wifi) access point 'Wifi name' has security, but secrets are required.
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2905] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2906] sup-iface[d11f817868ab38f9,0,wlan0]: wps: type pbc start...
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2909] device (wlan0): supplicant interface state: disconnected -> interface_disabled
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2919] device (wlan0): supplicant interface state: interface_disabled -> inactive
May 29 10:05:16 hostname wpa_supplicant[1232]: wlan0: WPS-PBC-ACTIVE
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2934] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2936] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2938] device (wlan0): Activation: (wifi) connection 'Wifi name' has security, and secrets exist.  No new secrets needed.
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2939] Config: added 'ssid' value 'Wifi name'
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2939] Config: added 'scan_ssid' value '1'
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2939] Config: added 'bgscan' value 'simple:30:-70:86400'
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2939] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK SAE FT-SAE'
May 29 10:05:16 hostname NetworkManager[1047]: <info>  [1653829516.2939] Config: added 'psk' value '<hidden>'
May 29 10:05:17 hostname wpa_supplicant[1232]: wlan0: WPS-CANCEL
May 29 10:05:17 hostname NetworkManager[1047]: <info>  [1653829517.7635] device (wlan0): supplicant interface state: inactive -> scanning
May 29 10:05:17 hostname wpa_supplicant[1232]: wlan0: SME: Trying to authenticate with f4:54:20:06:a2:38 (SSID='Wifi name' freq=5520 MHz)
May 29 10:05:17 hostname kernel: wlan0: authenticate with f4:54:20:06:a2:38
May 29 10:05:19 hostname kernel: wlan0: send auth to f4:54:20:06:a2:38 (try 1/3)
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.3813] device (wlan0): supplicant interface state: scanning -> authenticating
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: Trying to associate with f4:54:20:06:a2:38 (SSID='Wifi name' freq=5520 MHz)
May 29 10:05:19 hostname kernel: wlan0: authenticated
May 29 10:05:19 hostname kernel: wlan0: associate with f4:54:20:06:a2:38 (try 1/3)
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.3828] device (wlan0): supplicant interface state: authenticating -> associating
May 29 10:05:19 hostname kernel: wlan0: RX AssocResp from f4:54:20:06:a2:38 (capab=0x511 status=0 aid=36)
May 29 10:05:19 hostname kernel: ------------[ cut here ]------------
May 29 10:05:19 hostname kernel: Voluntary context switch within RCU read-side critical section!
May 29 10:05:19 hostname kernel: WARNING: CPU: 0 PID: 175 at kernel/rcu/tree_plugin.h:318 rcu_note_context_switch+0x5a2/0x620
May 29 10:05:19 hostname kernel: Modules linked in: snd_seq_dummy snd_hrtimer snd_seq snd_seq_device 88x2bu(OE) rtw88_8822bu eeepc_wmi asus_wmi rtw88_usb intel_rapl_msr sparse_keymap rtw88_8822b platform_profile intel_rapl_common video wmi_bmof rtw88_core edac_mce_amd mac80211 snd_hda_codec_realtek kvm_amd snd_hda_codec_generic snd_hda_codec_hdmi ledtrig_audio joydev kvm libarc4 vfat mousedev snd_hda_intel irqbypass rapl fat cfg80211 snd_intel_dspcfg rfkill sp5100_tco snd_intel_sdw_acpi snd_hda_codec pcspkr r8169 i2c_piix4 zenpower(OE) snd_hda_core realtek mdio_devres snd_hwdep libphy tpm_crb gpio_amdpt tpm_tis pinctrl_amd gpio_generic tpm_tis_core mac_hid wmi acpi_cpufreq lzo_rle pkcs8_key_parser snd_aloop snd_pcm snd_timer snd soundcore v4l2loopback_dc(OE) videodev mc crypto_user fuse zram bpf_preload ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 dm_crypt cbc encrypted_keys trusted asn1_encoder tee tpm dm_mod usbhid crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel
May 29 10:05:19 hostname kernel:  crypto_simd cryptd ccp nvme xhci_pci rng_core nvme_core xhci_pci_renesas nvidia_uvm(POE) nvidia_drm(POE) nvidia_modeset(POE) nvidia(POE)
May 29 10:05:19 hostname kernel: CPU: 0 PID: 175 Comm: kworker/u64:12 Tainted: P           OE     5.18.0-zen1-1-zen #1 8c1b4772d057e8d6ef1ec6c49ac9700bcd2a2e4e
May 29 10:05:19 hostname kernel: Hardware name: System manufacturer System Product Name/PRIME B450M-GAMING/BR, BIOS 3604 02/25/2022
May 29 10:05:19 hostname kernel: Workqueue: phy0 ieee80211_iface_work [mac80211]
May 29 10:05:19 hostname kernel: RIP: 0010:rcu_note_context_switch+0x5a2/0x620
May 29 10:05:19 hostname kernel: Code: 49 89 bc 24 a0 00 00 00 e9 14 fd ff ff 45 85 f6 75 ee e9 0a fd ff ff 48 c7 c7 10 f5 0e 85 c6 05 c3 10 e7 01 01 e8 be 03 be 00 <0f> 0b e9 b2 fa ff ff 49 83 bc 24 98 00 00 00 00 49 8b 84 24 a0 00
May 29 10:05:19 hostname kernel: RSP: 0018:ffffa472408979f0 EFLAGS: 00010082
May 29 10:05:19 hostname kernel: RAX: 0000000000000000 RBX: ffff8e699ea33b00 RCX: 0000000000000027
May 29 10:05:19 hostname kernel: RDX: ffff8e699ea216a8 RSI: 0000000000000001 RDI: ffff8e699ea216a0
May 29 10:05:19 hostname kernel: RBP: 0000000000000000 R08: 0000000000000001 R09: 00000000ffffffea
May 29 10:05:19 hostname kernel: R10: ffff8e69af24ec40 R11: 0000000000000001 R12: ffffa47240897bb0
May 29 10:05:19 hostname kernel: R13: ffff8e668df68000 R14: ffffa47240897b58 R15: ffffa47240897bb8
May 29 10:05:19 hostname kernel: FS:  0000000000000000(0000) GS:ffff8e699ea00000(0000) knlGS:0000000000000000
May 29 10:05:19 hostname kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
May 29 10:05:19 hostname kernel: CR2: 0000557069c31b88 CR3: 0000000130e38000 CR4: 0000000000350ef0
May 29 10:05:19 hostname kernel: Call Trace:
May 29 10:05:19 hostname kernel:  <TASK>
May 29 10:05:19 hostname kernel:  __schedule+0xb9/0x12f0
May 29 10:05:19 hostname kernel:  ? __mod_timer+0x42b/0x660
May 29 10:05:19 hostname kernel:  schedule+0x4f/0xb0
May 29 10:05:19 hostname kernel:  schedule_timeout+0x98/0x150
May 29 10:05:19 hostname kernel:  ? __bpf_trace_tick_stop+0x10/0x10
May 29 10:05:19 hostname kernel:  wait_for_completion_timeout+0x83/0x170
May 29 10:05:19 hostname kernel:  usb_start_wait_urb+0xa7/0x180
May 29 10:05:19 hostname kernel:  usb_control_msg+0xef/0x150
May 29 10:05:19 hostname kernel:  rtw_usb_read8_sync+0x88/0xd0 [rtw88_usb f34470ae608a8ee5a17dc1cb8f787501cf392d5d]
May 29 10:05:19 hostname kernel:  rtw_bf_enable_bfee_su+0x81/0x130 [rtw88_core 3a7f82ad2cbee0c7cd8e5be5e7a2133c7bb121e1]
May 29 10:05:19 hostname kernel:  rtw_bf_assoc+0x1eb/0x230 [rtw88_core 3a7f82ad2cbee0c7cd8e5be5e7a2133c7bb121e1]
May 29 10:05:19 hostname kernel:  rtw_ops_bss_info_changed+0x23f/0x250 [rtw88_core 3a7f82ad2cbee0c7cd8e5be5e7a2133c7bb121e1]
May 29 10:05:19 hostname kernel:  ieee80211_bss_info_change_notify+0xad/0x1b0 [mac80211 b11948457795bf34417cf9dbbbae49ef1c634fd1]
May 29 10:05:19 hostname kernel:  ieee80211_sta_rx_queued_mgmt.cold+0x10b1/0x1381 [mac80211 b11948457795bf34417cf9dbbbae49ef1c634fd1]
May 29 10:05:19 hostname kernel:  ieee80211_iface_work+0x317/0x430 [mac80211 b11948457795bf34417cf9dbbbae49ef1c634fd1]
May 29 10:05:19 hostname kernel:  process_one_work+0x255/0x410
May 29 10:05:19 hostname kernel:  worker_thread+0x55/0x4d0
May 29 10:05:19 hostname kernel:  ? process_one_work+0x410/0x410
May 29 10:05:19 hostname kernel:  kthread+0x13f/0x160
May 29 10:05:19 hostname kernel:  ? kthread_complete_and_exit+0x20/0x20
May 29 10:05:19 hostname kernel:  ret_from_fork+0x22/0x30
May 29 10:05:19 hostname kernel:  </TASK>
May 29 10:05:19 hostname kernel: ---[ end trace 0000000000000000 ]---
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: Associated with f4:54:20:06:a2:38
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
May 29 10:05:19 hostname kernel: wlan0: associated
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.4140] device (wlan0): supplicant interface state: associating -> associated
May 29 10:05:19 hostname kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by f4:54:20:06:a2:38
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.4478] device (wlan0): supplicant interface state: associated -> 4way_handshake
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: WPA: Key negotiation completed with f4:54:20:06:a2:38 [PTK=CCMP GTK=CCMP]
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-CONNECTED - Connection to f4:54:20:06:a2:38 completed [id=0 id_str=]
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5238] device (wlan0): supplicant interface state: 4way_handshake -> completed
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5238] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Wifi name"
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5239] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
May 29 10:05:19 hostname kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5244] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5389] dhcp4 (wlan0): state changed new lease, address=192.168.15.76
May 29 10:05:19 hostname dbus-daemon[1026]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=1047 comm="/usr/bin/NetworkManager --no-daemon")
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5401] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
May 29 10:05:19 hostname systemd[1]: Starting Network Manager Script Dispatcher Service...
May 29 10:05:19 hostname dbus-daemon[1026]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 29 10:05:19 hostname systemd[1]: Started Network Manager Script Dispatcher Service.
May 29 10:05:19 hostname audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5483] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5484] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5487] manager: NetworkManager state is now CONNECTED_LOCAL
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5493] manager: NetworkManager state is now CONNECTED_SITE
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5495] policy: set 'Wifi name' (wlan0) as default for IPv4 routing and DNS
May 29 10:05:19 hostname NetworkManager[1047]: <info>  [1653829519.5499] device (wlan0): Activation: successful, device activated.
May 29 10:05:19 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-55 noise=9999 txrate=1000
May 29 10:05:20 hostname systemd-timesyncd[1012]: Contacted time server 200.189.40.8:123 (2.arch.pool.ntp.org).
May 29 10:05:20 hostname NetworkManager[1047]: <info>  [1653829520.8507] dhcp6 (wlan0): activation: beginning transaction (timeout in 45 seconds)
May 29 10:05:20 hostname NetworkManager[1047]: <info>  [1653829520.8511] policy: set 'Wifi name' (wlan0) as default for IPv6 routing and DNS
May 29 10:05:21 hostname NetworkManager[1047]: <info>  [1653829521.0588] dhcp6 (wlan0): state changed new lease
May 29 10:05:22 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-BEACON-LOSS
May 29 10:05:24 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-BEACON-LOSS
May 29 10:05:26 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-BEACON-LOSS
May 29 10:05:29 hostname systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
May 29 10:05:29 hostname audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 29 10:05:29 hostname dbus-daemon[1026]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=1047 comm="/usr/bin/NetworkManager --no-daemon")
May 29 10:05:29 hostname systemd[1]: Starting Network Manager Script Dispatcher Service...
May 29 10:05:29 hostname dbus-daemon[1026]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 29 10:05:29 hostname systemd[1]: Started Network Manager Script Dispatcher Service.
May 29 10:05:29 hostname audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj==unconfined msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
May 29 10:05:34 hostname wpa_supplicant[1232]: wlan0: CTRL-EVENT-BEACON-LOSS
RinCat commented 2 years ago

I suspect you are using in kernel unfinished rtw88 driver. Any logs in dmesg and lsmod?

RinCat commented 2 years ago

I just updated the docs and you should see this.

giovanniPepi commented 2 years ago

I just updated the docs and you should see this.

Thank you! Definitely had rtw88_usb loaded, blacklisting it got RTW88x2BU working again