Bug#776816: firmware-realtek: fails to connect after a few suspends (or some uptime?)

To: Debian Bug Tracking System <submit@bugs.debian.org>
Subject: Bug#776816: firmware-realtek: fails to connect after a few suspends (or some uptime?)
From: Antoine Beaupré <anarcat@koumbit.org>
Date: Sun, 01 Feb 2015 23:06:41 -0500
Message-id: <[🔎] 20150202040641.2845.20275.reportbug@angela.anarc.at>
Reply-to: Antoine Beaupré <anarcat@koumbit.org>, 776816@bugs.debian.org

Package: firmware-realtek
Version: 0.43
Severity: normal

I started seeing this behavior after the upgrade from wheezy to jessie.
I am not sure it's directly related to the firmware, because I upgraded
it shortly before the upgrade. This is the history of upgrades, in
reverse order:

/var/log/dpkg.log.1:2014-12-30 17:35:43 upgrade firmware-realtek:all 0.43~bpo70+1 0.43
/var/log/dpkg.log.1:2014-12-05 15:46:29 upgrade firmware-realtek:all 0.41~bpo70+1 0.43~bpo70+1
/var/log/dpkg.log.10.gz:2014-03-23 20:14:57 upgrade firmware-realtek:all 0.40~bpo70+1 0.41~bpo70+1
/var/log/dpkg.log.12.gz:2014-01-19 14:10:55 upgrade firmware-realtek:all 0.39~bpo70+1 0.40~bpo70+1

It could also be the kernel's fault:

root@angela:/etc/ssh# grep linux-image /var/log/dpkg.log* | grep -v status
/var/log/dpkg.log:2015-01-23 15:59:56 remove linux-image-3.2.0-4-amd64:amd64 3.2.63-2+deb7u2 <aucune>
/var/log/dpkg.log:2015-01-23 16:00:05 purge linux-image-3.2.0-4-amd64:amd64 3.2.63-2+deb7u2 <aucune>
/var/log/dpkg.log.1:2014-12-09 15:35:48 upgrade linux-image-3.2.0-4-amd64:amd64 3.2.63-2+deb7u1 3.2.63-2+deb7u2
/var/log/dpkg.log.1:2014-12-09 15:36:14 configure linux-image-3.2.0-4-amd64:amd64 3.2.63-2+deb7u2 <none>
/var/log/dpkg.log.1:2014-12-30 18:33:13 install linux-image-3.16.0-4-amd64:amd64 <aucune> 3.16.7-ckt2-1
/var/log/dpkg.log.1:2014-12-30 18:42:23 upgrade linux-image-amd64:amd64 3.2+46 3.16+63
/var/log/dpkg.log.1:2014-12-30 18:53:07 configure linux-image-3.16.0-4-amd64:amd64 3.16.7-ckt2-1 <aucune>
/var/log/dpkg.log.1:2014-12-30 19:50:42 configure linux-image-amd64:amd64 3.16+63 <aucune>

notice how that clever boy of yours uninstalled the previous kernel, making it
difficult to test the regression. i'll try to find one of those somewhere...

I believe the problem may have started in december. I recall having
similar issues in the past, but reloading the driver would always fix
it:

modprobe -r rtl8192ce
modprobe rtl8192ce

but now this doesn't work anymore. nothing short of a reboot can restore
proper wifi. this may be related to secure hotspots but since they are
so frequent nowadays it's hard to tell.

here's a typical failing NM chitchat:

Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) starting connection 'CrapN6'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb  1 22:44:24 angela NetworkManager[682]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Feb  1 22:44:24 angela NetworkManager[682]: <info> NetworkManager state is now CONNECTING
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb  1 22:44:24 angela NetworkManager[682]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0/wireless): access point 'CrapN6' has security, but secrets are required.
Feb  1 22:44:24 angela NetworkManager[682]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb  1 22:44:24 angela NetworkManager[682]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Feb  1 22:44:24 angela NetworkManager[682]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0/wireless): connection 'CrapN6' has security, and secrets exist.  No new secrets needed.
Feb  1 22:44:24 angela NetworkManager[682]: <info> Config: added 'ssid' value 'CrapN6'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Config: added 'scan_ssid' value '1'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Config: added 'auth_alg' value 'OPEN'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Config: added 'psk' value '<omitted>'
Feb  1 22:44:24 angela NetworkManager[682]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb  1 22:44:25 angela NetworkManager[682]: <info> Config: set interface ap_scan to 1
Feb  1 22:44:25 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb  1 22:44:35 angela wpa_supplicant[2160]: wlan0: SME: Trying to authenticate with f4:ec:38:e2:f9:68 (SSID='CrapN6' freq=2412 MHz)
Feb  1 22:44:35 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: scanning -> authenticating
Feb  1 22:44:40 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
Feb  1 22:44:41 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: disconnected -> scanning
Feb  1 22:44:50 angela NetworkManager[682]: <warn> Activation (wlan0/wireless): association took too long, failing activation.
Feb  1 22:44:50 angela NetworkManager[682]: <info> (wlan0): device state change: config -> failed (reason 'ssid-not-found') [50 120 53]
Feb  1 22:44:50 angela NetworkManager[682]: <info> NetworkManager state is now DISCONNECTED
Feb  1 22:44:50 angela NetworkManager[682]: <info> Disabling autoconnect for connection 'CrapN6'.
Feb  1 22:44:50 angela NetworkManager[682]: <warn> Activation (wlan0) failed for connection 'CrapN6'
Feb  1 22:44:50 angela NetworkManager[682]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Feb  1 22:44:50 angela NetworkManager[682]: <info> (wlan0): deactivating device (reason 'none') [0]
Feb  1 22:44:50 angela wpa_supplicant[2160]: wlan0: Reject scan trigger since one is already pending
Feb  1 22:44:50 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: scanning -> disconnected
Feb  1 22:44:50 angela NetworkManager[682]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
Feb  1 22:44:50 angela NetworkManager[682]: <warn> Could not get scan request result: Scan request rejected

so the above is a timeout. it would often be followed by another similar
error, but notice the CONN_FAILED:


Feb  1 22:45:03 angela wpa_supplicant[2160]: wlan0: SME: Trying to authenticate with f4:ec:38:e2:f9:68 (SSID='CrapN6' freq=2412 MHz)
Feb  1 22:45:03 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: disconnected -> authenticating
Feb  1 22:45:08 angela wpa_supplicant[2160]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="CrapN6" auth_failures=1 duration=10 reason=CONN_FAILED
Feb  1 22:45:08 angela NetworkManager[682]: <info> (wlan0): supplicant interface state: authenticating -> disconnected

wpa_supplicant would also warn me about:

Feb  1 22:45:51 angela wpa_supplicant[2160]: wlan0: Reject scan trigger since one is already pending
Feb  1 22:45:51 angela wpa_supplicant[2160]: wlan0: Failed to initiate AP scan

and here's the kind of things the kernel had to say for its sorry self:

Feb  1 22:45:03 angela kernel: [ 7509.781379] wlan0: authenticate with f4:ec:38:e2:f9:68
Feb  1 22:45:03 angela kernel: [ 7509.796904] wlan0: send auth to f4:ec:38:e2:f9:68 (try 1/3)
Feb  1 22:45:03 angela kernel: [ 7509.803235] wlan0: authenticated
Feb  1 22:45:08 angela kernel: [ 7514.799136] wlan0: aborting authentication with f4:ec:38:e2:f9:68 by local choice (Reason: 3=DEAUTH_LEAVING)
Feb  1 22:45:23 angela kernel: [ 7529.805590] wlan0: authenticate with f4:ec:38:e2:f9:68

i did try to swap out a new network card in this stupid machine, but the
equally stupid BIOS wouldn't let me.

yay proprietary hardware... :/

-- System Information:
Debian Release: 8.0
  APT prefers testing
  APT policy: (500, 'testing')
Architecture: amd64 (x86_64)

Kernel: Linux 3.16.0-4-amd64 (SMP w/2 CPU cores)
Locale: LANG=fr_CA.UTF-8, LC_CTYPE=fr_CA.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

firmware-realtek depends on no packages.

firmware-realtek recommends no packages.

Versions of packages firmware-realtek suggests:
ii  initramfs-tools  0.116

-- no debconf information

Reply to:

Follow-Ups:
- Processed: Re: Bug#776816: Acknowledgement (firmware-realtek: fails to connect after a few suspends (or some uptime?))
  - From: owner@bugs.debian.org (Debian Bug Tracking System)
- Processed: Re: Bug#776816: Acknowledgement (firmware-realtek: fails to connect after a few suspends (or some uptime?))
  - From: owner@bugs.debian.org (Debian Bug Tracking System)

Prev by Date: linux-tools_3.18.5-1~exp1_multi.changes ACCEPTED into experimental, experimental
Next by Date: Processed: tagging 771340, reassign 771340 to src:linux-tools, found 771340 in 3.16-2 ...
Previous by thread: linux-tools_3.18.5-1~exp1_multi.changes ACCEPTED into experimental, experimental
Next by thread: Bug#776816: Acknowledgement (firmware-realtek: fails to connect after a few suspends (or some uptime?))
Index(es):
- Date
- Thread