Public bug reported:
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.
** Affects: linux-firmware (Ubuntu)
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to linux-firmware in Ubuntu.
https://bugs.launchpad.net/bugs/1578796
Title:
1.127.22 causes wifi instability on Intel N7260 chipset
Status in linux-firmware package in Ubuntu:
New
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-firmware/+bug/1578796/+subscriptions
--
Mailing list: https://launchpad.net/~kernel-packages
Post to : [email protected]
Unsubscribe : https://launchpad.net/~kernel-packages
More help : https://help.launchpad.net/ListHelp
