1.127.22 causes wifi instability on Intel N7260 chipset

Bug #1578796 reported by Jeremy
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Expired
Medium
Unassigned

Bug Description

OS: Linux Mint 17 Qiana (based on Ubuntu 14.04 Trusty)
Package Version: linux-firmware 1.127.22.0

After upgrading to 1.127.22, my wifi on my lenovo x240 became unstable. It would connect, then after less than ten minutes it would somehow disassociate from the AP, and only cycling the hardware wifi switch would bring it back. A typical portion of /var/log/syslog during the course of the problem would look like:

May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0): bringing up device.
May 2 19:43:54 MACHINENAME kernel: [57059.429299] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
May 2 19:43:54 MACHINENAME kernel: [57059.430096] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> WiFi hardware radio set enabled
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> WiFi now enabled by radio killswitch
May 2 19:43:54 MACHINENAME kernel: [57059.447505] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0) supports 5 scan SSIDs
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: starting -> ready
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: unavailable -> disconnected (reason 'supplicant-available') [20 30 42]
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <warn> Trying to remove a non-existant call id.
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: ready -> disconnected
May 2 19:43:54 MACHINENAME NetworkManager[1063]: <info> (wlan0) supports 5 scan SSIDs
May 2 19:43:54 MACHINENAME wpa_supplicant[1726]: wlan0: Reject scan trigger since one is already pending
May 2 19:43:54 MACHINENAME wpa_supplicant[1726]: wlan0: CTRL-EVENT-SCAN-STARTED
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: disconnected -> inactive
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Auto-activating connection 'Auto XXXXX'.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) starting connection 'Auto XXXXX'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> NetworkManager state is now CONNECTING
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0/wireless): access point 'Auto XXXXX' has security, but secrets are required.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: config -> need-auth (reason 'none') [50 60 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: prepare -> config (reason 'none') [40 50 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0/wireless): connection 'Auto XXXXX' has security, and secrets exist. No new secrets needed.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: added 'ssid' value 'XXXXX'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: added 'scan_ssid' value '1'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: added 'key_mgmt' value 'WPA-PSK'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: added 'auth_alg' value 'OPEN'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: added 'psk' value '<omitted>'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Config: set interface ap_scan to 1
May 2 19:43:55 MACHINENAME wpa_supplicant[1726]: wlan0: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='XXXXX' freq=2447 MHz)
May 2 19:43:55 MACHINENAME kernel: [57059.971562] wlan0: authenticate with XX:XX:XX:XX:XX:XX
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: inactive -> authenticating
May 2 19:43:55 MACHINENAME kernel: [57059.975238] wlan0: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
May 2 19:43:55 MACHINENAME wpa_supplicant[1726]: wlan0: Trying to associate with XX:XX:XX:XX:XX:XX (SSID='XXXXX' freq=2447 MHz)
May 2 19:43:55 MACHINENAME kernel: [57059.977372] wlan0: authenticated
May 2 19:43:55 MACHINENAME kernel: [57059.981323] wlan0: associate with XX:XX:XX:XX:XX:XX (try 1/3)
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: authenticating -> associating
May 2 19:43:55 MACHINENAME kernel: [57059.985407] wlan0: RX AssocResp from XX:XX:XX:XX:XX:XX (capab=0x1411 status=0 aid=3)
May 2 19:43:55 MACHINENAME wpa_supplicant[1726]: wlan0: Associated with XX:XX:XX:XX:XX:XX
May 2 19:43:55 MACHINENAME kernel: [57059.989688] wlan0: associated
May 2 19:43:55 MACHINENAME kernel: [57059.989720] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: associating -> 4-way handshake
May 2 19:43:55 MACHINENAME wpa_supplicant[1726]: wlan0: WPA: Key negotiation completed with XX:XX:XX:XX:XX:XX [PTK=CCMP GTK=CCMP]
May 2 19:43:55 MACHINENAME wpa_supplicant[1726]: wlan0: CTRL-EVENT-CONNECTED - Connection to XX:XX:XX:XX:XX:XX completed [id=0 id_str=]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'XXXXX'.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0]
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds)
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> dhclient started with pid 25167
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Beginning IP6 addrconf.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): DHCPv4 state changed nbi -> preinit
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): DHCPv4 state changed preinit -> reboot
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> address 192.168.0.5
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> prefix 24 (255.255.255.0)
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> gateway 192.168.0.1
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> nameserver '192.168.0.1'
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Configure Commit) scheduled...
May 2 19:43:55 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) started...
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 5 of 5 (IPv4 Commit) complete.
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: secondaries -> activated (reason 'none') [90 100 0]
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> NetworkManager state is now CONNECTED_GLOBAL
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> Policy set 'Auto XXXXX' (wlan0) as default for IPv4 routing and DNS.
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> Writing DNS information to /sbin/resolvconf
May 2 19:43:56 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) successful, device activated.
May 2 19:43:56 MACHINENAME dbus[575]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
May 2 19:43:56 MACHINENAME dbus[575]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 2 19:44:15 MACHINENAME NetworkManager[1063]: <info> (wlan0): IP6 addrconf timed out or failed.
May 2 19:44:15 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) scheduled...
May 2 19:44:15 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) started...
May 2 19:44:15 MACHINENAME NetworkManager[1063]: <info> Activation (wlan0) Stage 4 of 5 (IPv6 Configure Timeout) complete.
May 2 19:44:17 MACHINENAME wpa_supplicant[1726]: wlan0: CTRL-EVENT-SCAN-STARTED
May 2 19:44:51 MACHINENAME kernel: [57116.406291] e1000e 0000:00:19.0: irq 61 for MSI/MSI-X
May 2 19:47:45 MACHINENAME kernel: [57290.016074] thinkpad_ec: thinkpad_ec_request_row: arg0 rejected: (0x01:0x00)->0x00
May 2 19:47:45 MACHINENAME kernel: [57290.016080] thinkpad_ec: thinkpad_ec_read_row: failed requesting row: (0x01:0x00)->0xfffffffb
May 2 19:47:45 MACHINENAME kernel: [57290.016082] thinkpad_ec: initial ec test failed
May 2 19:47:45 MACHINENAME kernel: [57290.105637] thinkpad_acpi: EC reports that Thermal Table has changed
May 2 19:47:45 MACHINENAME anacron[25964]: Anacron 2.3 started on 2016-05-02
May 2 19:47:45 MACHINENAME anacron[25964]: Normal exit (0 jobs run)
May 2 19:48:55 MACHINENAME kernel: [57360.202372] wlan0: disassociated from XX:XX:XX:XX:XX:XX (Reason: 7)
May 2 19:48:55 MACHINENAME hostapd: wlan0: STA XX:XX:XX:XX:XX:XX IEEE 802.11: disassociated
May 2 19:47:26 MACHINENAME wpa_supplicant[1726]: message repeated 3 times: [ wlan0: CTRL-EVENT-SCAN-STARTED ]
May 2 19:48:55 MACHINENAME wpa_supplicant[1726]: wlan0: CTRL-EVENT-DISCONNECTED bssid=XX:XX:XX:XX:XX:XX reason=7
May 2 19:48:55 MACHINENAME wpa_supplicant[1726]: wlan0: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='XXXXX' freq=2447 MHz)
May 2 19:48:55 MACHINENAME NetworkManager[1063]: <warn> Connection disconnected (reason 7)
May 2 19:48:55 MACHINENAME kernel: [57360.248867] wlan0: deauthenticating from XX:XX:XX:XX:XX:XX by local choice (reason=3)
May 2 19:48:55 MACHINENAME kernel: [57360.248950] cfg80211: Calling CRDA to update world regulatory domain
May 2 19:48:55 MACHINENAME wpa_supplicant[1726]: wlan0: CTRL-EVENT-SCAN-STARTED
May 2 19:48:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: completed -> authenticating
May 2 19:48:55 MACHINENAME kernel: [57360.256323] cfg80211: World regulatory domain updated:
May 2 19:48:55 MACHINENAME kernel: [57360.256331] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
May 2 19:48:55 MACHINENAME kernel: [57360.256337] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.256341] cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.256345] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.256348] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.256352] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.256392] cfg80211: Calling CRDA for country: US
May 2 19:48:55 MACHINENAME kernel: [57360.258939] cfg80211: Regulatory domain changed to country: US
May 2 19:48:55 MACHINENAME kernel: [57360.258942] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
May 2 19:48:55 MACHINENAME kernel: [57360.258944] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258945] cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258946] cfg80211: (5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258947] cfg80211: (5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258948] cfg80211: (5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258949] cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
May 2 19:48:55 MACHINENAME kernel: [57360.258951] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 4000 mBm)
May 2 19:48:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: authenticating -> disconnected
May 2 19:48:55 MACHINENAME NetworkManager[1063]: <info> (wlan0): supplicant interface state: disconnected -> scanning
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <warn> (wlan0): link timed out.
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: activated -> failed (reason 'SSID not found') [100 120 53]
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> NetworkManager state is now DISCONNECTED
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <warn> Activation (wlan0) failed for connection 'Auto XXXXX'
May 2 19:49:10 MACHINENAME dbus[575]: [system] Activating service name='org.freedesktop.nm_dispatcher' (using servicehelper)
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> (wlan0): deactivating device (reason 'none') [0]
May 2 19:49:10 MACHINENAME dbus[575]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> (wlan0): canceled DHCP transaction, DHCP client pid 25167
May 2 19:49:10 MACHINENAME kernel: [57375.721732] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <warn> DNS: plugin dnsmasq update failed
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <info> Removing DNS information from /sbin/resolvconf
May 2 19:49:10 MACHINENAME NetworkManager[1063]: <warn> Couldn't disconnect supplicant interface: This interface is not connected.
May 2 19:56:30 MACHINENAME NetworkManager[1063]: <info> (wlan0): device state change: disconnected -> unavailable (reason 'none') [30 20 0]
May 2 19:56:30 MACHINENAME NetworkManager[1063]: <info> (wlan0): deactivating device (reason 'none') [0]
May 2 19:56:30 MACHINENAME NetworkManager[1063]: <info> (wlan0): taking down device.
May 2 19:56:30 MACHINENAME NetworkManager[1063]: <info> WiFi hardware radio set disabled
May 2 19:56:30 MACHINENAME NetworkManager[1063]: <info> WiFi now disabled by radio killswitch

To walk you through it, I hardware-enabled wifi at the beginning of the log. By 19:44:17, wifi is up and working fine. At 19:48:55, the interface disassociates from the AP (reason=7). It tries to reconnect, but fails, and I don't notice until the end of the log, at which point I hardware disable wifi and the whole process starts all over.

Downgrading linux-firmware back to 1.127.20 solved this problem for me.

I'm happy to test patches or temporarily upgrade back to 1.127.22 to provide more detailed log info.

Revision history for this message
Joseph Salisbury (jsalisbury) wrote :

Would it be possible for you to test the latest upstream kernel? Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Please test the latest v4.6 kernel[0].

If this bug is fixed in the mainline kernel, please add the following tag 'kernel-fixed-upstream'.

If the mainline kernel does not fix this bug, please add the tag: 'kernel-bug-exists-upstream'.

Once testing of the upstream kernel is complete, please mark this bug as "Confirmed".

Thanks in advance.

[0] http://kernel.ubuntu.com/~kernel-ppa/mainline/v4.6-rc6-wily/

Changed in linux-firmware (Ubuntu):
importance: Undecided → Medium
affects: linux-firmware (Ubuntu) → linux (Ubuntu)
Changed in linux (Ubuntu):
status: New → Incomplete
Revision history for this message
Jeremy (jgillula) wrote :

Just to clarify, you want me to install the latest upstream kernel *and* linux-firmware 1.127.22 to see if the problem still occurs or not? Or just the latest upstream kernel?

Revision history for this message
penalvch (penalvch) wrote :

Jeremy, while booted into the firmware that works better, please execute the following command only once, as it will automatically gather debugging information, in a terminal:
apport-collect 1578796

When reporting bugs in the future please use apport by using 'ubuntu-bug' and the name of the package affected. You can learn more about this functionality at https://wiki.ubuntu.com/ReportingBugs.

Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for linux (Ubuntu) because there has been no activity for 60 days.]

Changed in linux (Ubuntu):
status: Incomplete → Expired
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.