kernel-packages team mailing list archive

Thread
Date
[Bug 1578796] Re: 1.127.22 causes wifi instability on Intel N7260 chipset

To: kernel-packages@xxxxxxxxxxxxxxxxxxx
From: "Christopher M. Penalver" <christopher.m.penalver@xxxxxxxxx>
Date: Sun, 05 Jun 2016 13:25:57 -0000
Reply-to: Bug 1578796 <1578796@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
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.

-- 
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to linux in Ubuntu.
https://bugs.launchpad.net/bugs/1578796

Title:
  1.127.22 causes wifi instability on Intel N7260 chipset

Status in linux package in Ubuntu:
  Incomplete

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.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1578796/+subscriptions
References

[Bug 1578796] [NEW] 1.127.22 causes wifi instability on Intel N7260 chipset
From: Jeremy, 2016-05-05