Wireless randomly refuses connections

raskug · 2013-02-05 22:26:29

'Yello, first time Archer here. I got myself a brand new Lenovo Thinkpad Edge E530 and wanted to break away from the Ubuntusphere with it, and aside from a few naggles (I couldn't get magmakeys and automounting to work without a DE, but now I run Cinnamon so they're an issue for another day), everything works... except for some bizarre behavior with the wifi.

Seemingly at random whenever I try to initiate some internet activity (sudo pacman -S, opening a link in browser, git clone, fetching mail, etc) the action fails immediately, as if no internet connection was present. Trying it again usually succeeds, but sometimes it might require several tries. Nevertheless, NetworkManager never reports wireless as down, and neither do iwconfig or ip link.

My home network (WPA2-PSK) might be partially at fault, as this problem has not cropped up in any other wireless network I've connected to with this device... but Windows, Android and Ubuntu all work fine at home, so clearly there must be something I can do to make Arch play nice, too.

Here's my breadcrumb trail:

$ iwconfig
wlp3s0    IEEE 802.11bgn  ESSID:"SkyNET2.0"  
          Mode:Managed  Frequency:2.412 GHz  Access Point: CC:5D:4E:7A:BB:47   
          Bit Rate=1 Mb/s   Tx-Power=16 dBm   
          Retry  long limit:7   RTS thr:off   Fragment thr:off
          Power Management:off
          Link Quality=50/70  Signal level=-60 dBm  
          Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:18100  Invalid misc:104   Missed beacon:0

lo        no wireless extensions.

enp12s0   no wireless extensions.

$ ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT 
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: enp12s0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc pfifo_fast state DOWN mode DEFAULT qlen 1000
    link/ether b8:88:e3:e8:73:ed brd ff:ff:ff:ff:ff:ff
3: wlp3s0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode DORMANT qlen 1000
    link/ether 60:36:dd:7e:1b:0c brd ff:ff:ff:ff:ff:ff

$ lspci -k
00:00.0 Host bridge: Intel Corporation 3rd Gen Core processor DRAM Controller (rev 09)
	Subsystem: Lenovo Device 5000
00:02.0 VGA compatible controller: Intel Corporation 3rd Gen Core processor Graphics Controller (rev 09)
	Subsystem: Lenovo Device 5001
	Kernel driver in use: i915
00:14.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB xHCI Host Controller (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: xhci_hcd
00:16.0 Communication controller: Intel Corporation 7 Series/C210 Series Chipset Family MEI Controller #1 (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: mei
00:1a.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #2 (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: ehci_hcd
00:1b.0 Audio device: Intel Corporation 7 Series/C210 Series Chipset Family High Definition Audio Controller (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: snd_hda_intel
00:1c.0 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 1 (rev c4)
	Kernel driver in use: pcieport
00:1c.1 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 2 (rev c4)
	Kernel driver in use: pcieport
00:1c.2 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 3 (rev c4)
	Kernel driver in use: pcieport
00:1c.3 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 4 (rev c4)
	Kernel driver in use: pcieport
00:1d.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #1 (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: ehci_hcd
00:1f.0 ISA bridge: Intel Corporation HM77 Express Chipset LPC Controller (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: lpc_ich
00:1f.2 SATA controller: Intel Corporation 7 Series Chipset Family 6-port SATA Controller [AHCI mode] (rev 04)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: ahci
00:1f.3 SMBus: Intel Corporation 7 Series/C210 Series Chipset Family SMBus Controller (rev 04)
	Subsystem: Lenovo Device 5000
02:00.0 Unassigned class [ff00]: Realtek Semiconductor Co., Ltd. RTS5229 PCI Express Card Reader (rev 01)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: rts5229
03:00.0 Network controller: Intel Corporation Centrino Wireless-N 2230 (rev c4)
	Subsystem: Intel Corporation Centrino Wireless-N 2230 BGN
	Kernel driver in use: iwlwifi
0c:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 07)
	Subsystem: Lenovo Device 5000
	Kernel driver in use: r8169

$ lsmod | grep iwlwifi
iwlwifi               125974  1 iwldvm
cfg80211              179435  3 iwlwifi,mac80211,iwldvm

$ dmesg | grep -E 'iwlwifi|iwldvm|mac80211|cfg80211'
[    4.611490] cfg80211: Calling CRDA to update world regulatory domain
[    4.623446] iwlwifi 0000:03:00.0: pci_resource_len = 0x00002000
[    4.623449] iwlwifi 0000:03:00.0: pci_resource_base = ffffc90000c7c000
[    4.623452] iwlwifi 0000:03:00.0: HW Revision ID = 0xC4
[    4.623597] iwlwifi 0000:03:00.0: irq 44 for MSI/MSI-X
[    4.629439] iwlwifi 0000:03:00.0: loaded firmware version 18.168.6.1
[    5.344983] iwldvm: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:
[    5.344985] iwldvm: Copyright(c) 2003-2012 Intel Corporation
[    5.345003] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEBUG disabled
[    5.345005] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEBUGFS disabled
[    5.345007] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEVICE_TRACING enabled
[    5.345008] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEVICE_TESTMODE disabled
[    5.345010] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_P2P disabled
[    5.345012] iwlwifi 0000:03:00.0: Detected Intel(R) Centrino(R) Wireless-N 2230 BGN, REV=0xC8
[    5.345115] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[    5.362694] iwlwifi 0000:03:00.0: device EEPROM VER=0x81c, CALIB=0x6
[    5.362697] iwlwifi 0000:03:00.0: Device SKU: 0x150
[    5.362698] iwlwifi 0000:03:00.0: Valid Tx ant: 0x3, Valid Rx ant: 0x3
[    5.916173] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[    5.923750] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[    6.287712] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[    6.295279] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 2207.578899] cfg80211: Calling CRDA to update world regulatory domain
[ 2208.192011] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 2208.199594] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 2213.960562] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 2213.968146] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 2936.516598] cfg80211: Calling CRDA to update world regulatory domain
[ 2937.104475] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 2937.112097] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 2942.568875] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 2942.576474] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 4695.905778] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 4695.913385] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 4701.373248] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 4701.380816] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 5555.892632] cfg80211: Calling CRDA for country: FI
[ 5556.507481] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 5556.515082] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 5561.979074] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 5561.986654] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 7095.643037] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 7095.650628] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[ 7101.366908] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[ 7101.374495] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[22496.075704] cfg80211: Calling CRDA to update world regulatory domain
[22496.751160] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[22496.759066] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0
[22502.241346] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[22502.248920] iwlwifi 0000:03:00.0: Radio type=0x2-0x0-0x0

The trail of that log looks suspicious as hell, but I don't know jack about, dmesg, so. The usual suspects (iwconfig wlp3s0 power off, disabling IPv6 in NetworkManager, trying Wicd and netcfg) did not help. Ideas?

Last edited by raskug (2013-02-05 22:34:14)

the sad clown · 2013-02-06 01:41:38

I would want to broaden your search. Next time it fails, note the time and run this:

journalctl --since="2013-02-05 12:34:56" --until="2013-02-05 13:34:56"

Adjust to make sure you are bracketing the time frame of the incident. Is there a reason you didn't include dhcpcd (or dhclient if that is what you use) in your list of suspects?

raskug · 2013-02-06 14:51:59

the sad clown wrote:

I would want to broaden your search. Next time it fails, note the time and run this:
journalctl --since="2013-02-05 12:34:56" --until="2013-02-05 13:34:56"
Adjust to make sure you are bracketing the time frame of the incident.

Here's one right after a failed pacman refresh:

helmi 06 16:38:07 nasu sudo[911]: rasku : TTY=pts/0 ; PWD=/home/rasku ; USER=root ; COMMAND=/usr/bin/pacman -Syy
helmi 06 16:38:07 nasu sudo[911]: pam_unix(sudo:session): session opened for user root by rasku(uid=0)
helmi 06 16:38:16 nasu sudo[911]: pam_unix(sudo:session): session closed for user root
helmi 06 16:38:46 nasu sudo[917]: rasku : TTY=pts/0 ; PWD=/home/rasku ; USER=root ; COMMAND=/usr/bin/journalctl --since=2013-02-06 16:38:00 --until=2013-02-06 16:39:00
helmi 06 16:38:46 nasu sudo[917]: pam_unix(sudo:session): session opened for user root by rasku(uid=0)

Is there a reason you didn't include dhcpcd (or dhclient if that is what you use) in your list of suspects?

Yeah: I didn't know what either of those are. Some Googling later I'm not much wiser. All I can tell is that both are installed but neither seems to be running (not in systemctl or ps aux.)

raskug · 2013-02-14 19:31:15

I did some googling around for my network card and unsurprisingly found people having lots of different problems with it, but nothing quite similar to mine. Regardless, I tried some of the module options that seemed to alleviate their problems (11n_disable=1, bt_coex_active=N, power_save=N, wd_disable=1) to no effect.

I'm starting to think the problem isn't the card or the driver anyway. I had temporary access to a tablet using an Atheros wireless card with the ath5k module, and it had the exact same problem with Arch. Ubuntu worked on it flawlessly. (Or well, not flawlessly, the touchscreen was a mess.)

So what does that leave? The router? NetworkManager settings? I wonder what sort of dark magics Ubuntu is using to get Linux to play nice with my home network.

Last edited by raskug (2013-02-14 19:31:54)

frank604 · 2013-02-14 19:41:44

Have you tried to eliminate networkmanager by using netcfg https://wiki.archlinux.org/index.php/Netcfg
Then if the same is happening, at least we tick one off the list.

https://wiki.archlinux.org/index.php/Beginners'_Guide#Wireless_2
hope it helps

Last edited by frank604 (2013-02-14 19:42:32)

raskug · 2013-02-15 17:55:58

Yeah, I already tried both netcfg and Wicd. Changed nothing.

the sad clown · 2013-02-15 18:24:19

You don't need both dhcpcd and dhclient installed, since they both do the same thing. And what I meant was that you performed grep on your dmesg log. You should have included one of those (which ever you are using to establish a dhcp connection) in your troubleshooting. Or are you using a static address?

Here is my suggestion. Make the connection by hand. Do these steps and watch for failures:

ip link set yourwirelessinterface up
wpa_passphrase yourssid yourpassphrase > testconfig
wpa_supplicant -d -i yourwirelessinterface -c testconfig
dhcpcd

The ip link step is probably not necessary given your situation. The wpa_passphrase command is creating a configuration file for wpa_supplicant to use. And don't forget to replace all of the your*** entries with values from your system. Then report back what happens. Oh, and this is only for testing. Typically, you wouldn't use the '-d' option unless you are debugging with wpa_supplicant. If you want to actually use it, replace that option with '-B' to background the process.

Last edited by the sad clown (2013-02-15 18:26:33)

raskug · 2013-02-18 17:25:05

Oh, right, dhcpcd is a dependency of netcfg, which I still had installed. Disregard that.

And I'm not sure if I'm using any of {dhcpcd,dhclient,static IP}. dhclient is a dependency of NetworkManager and I seem to recall reading that it uses it internally, but I haven't touched a single dhclient configuration file, and it doesn't show up in any of dmesg, systemctl, or ps aux. I certainly haven't set up a static IP.

Anyways, I stopped NetworkManager and executed those commands. wpa_supplicant blocked at "EAPOL: disable timer tick" until I executed "sudo dhclient wlp3s0" in a separate terminal, where it stayed for a little less than half a minute before apparently detaching to the background (visible in ps aux). After that, I got internet access, but it still has those hiccups and wpa_supplicant doesn't report anything when they happen. Here's the full log for completeness:

$ sudo wpa_supplicant -d -i wlp3s0 -c testconfig 
wpa_supplicant v2.0
Successfully initialized wpa_supplicant
Initializing interface 'wlp3s0' conf 'testconfig' driver 'default' ctrl_interface 'N/A' bridge 'N/A'
Configuration file 'testconfig' -> '/home/rasku/testconfig'
Reading configuration file '/home/rasku/testconfig'
Priority group 0
   id=0 ssid='SkyNET2.0'
WEXT: cfg80211-based driver detected
wext: interface wlp3s0 phy: phy0
rfkill: initial event: idx=1 type=2 op=0 soft=0 hard=0
rfkill: initial event: idx=2 type=1 op=0 soft=0 hard=0
rfkill: initial event: idx=6 type=2 op=0 soft=1 hard=0
SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
  capabilities: key_mgmt 0xf enc 0x1f flags 0x0
netlink: Operstate: linkmode=1, operstate=5
wlp3s0: Own MAC address: 60:36:dd:7e:1b:0c
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_countermeasures
wlp3s0: RSN: flushing PMKID list in the driver
wlp3s0: Setting scan request: 0 sec 100000 usec
WPS: Set UUID for interface wlp3s0
WPS: UUID based on MAC address - hexdump(len=16): 78 33 44 8e 61 e7 59 12 b5 d6 cb ff 6e 7a 25 51
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: Supplicant port status: Unauthorized
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
wlp3s0: Added interface wlp3s0
wlp3s0: State: DISCONNECTED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b06 len=12
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=16
wlp3s0: State: DISCONNECTED -> SCANNING
wlp3s0: Starting AP scan for wildcard SSID
Scan requested (ret=0) - scan timeout 10 seconds
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b19 len=16
wlp3s0: Event SCAN_RESULTS (3) received
Scan results did not fit - trying larger buffer (8192 bytes)
Received 5173 bytes of scan results (9 BSSes)
wlp3s0: BSS: Start scan result update 1
wlp3s0: BSS: Add new id 0 BSSID cc:5d:4e:7a:bb:47 SSID 'SkyNET2.0'
wlp3s0: BSS: Add new id 1 BSSID 70:71:bc:51:d3:1b SSID '17e855'
wlp3s0: BSS: Add new id 2 BSSID 00:0c:c3:d3:41:cd SSID 'ElisaKoti04'
wlp3s0: BSS: Add new id 3 BSSID e8:40:f2:56:b7:89 SSID 'HannumoiJnen'
wlp3s0: BSS: Add new id 4 BSSID cc:5d:4e:a2:88:6f SSID 'ZyXEL_9444'
wlp3s0: BSS: Add new id 5 BSSID e8:40:f2:50:8a:ec SSID 'f40d53'
wlp3s0: BSS: Add new id 6 BSSID 38:60:77:cc:3c:b6 SSID 'varamies'
wlp3s0: BSS: Add new id 7 BSSID b4:07:f9:1f:77:6b SSID 'Piian puhelin '
wlp3s0: BSS: Add new id 8 BSSID e8:40:f2:56:0b:05 SSID 'f400c9'
BSS: last_scan_res_used=9/32 last_scan_full=0
wlp3s0: New scan results available
WPS: AP 70:71:bc:51:d3:1b type 0 added
WPS: AP 00:0c:c3:d3:41:cd type 0 added
WPS: AP e8:40:f2:56:b7:89 type 0 added
WPS: AP e8:40:f2:50:8a:ec type 0 added
WPS: AP 38:60:77:cc:3c:b6 type 0 added
WPS: AP e8:40:f2:56:0b:05 type 0 added
WPS: AP[0] 70:71:bc:51:d3:1b type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[1] 00:0c:c3:d3:41:cd type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[2] e8:40:f2:56:b7:89 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[3] e8:40:f2:50:8a:ec type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[4] 38:60:77:cc:3c:b6 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
WPS: AP[5] e8:40:f2:56:0b:05 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
wlp3s0: Selecting BSS from priority group 0
wlp3s0: 0: cc:5d:4e:7a:bb:47 ssid='SkyNET2.0' wpa_ie_len=0 rsn_ie_len=24 caps=0x11 level=-35
wlp3s0:    selected based on RSN IE
wlp3s0:    selected BSS cc:5d:4e:7a:bb:47 ssid='SkyNET2.0'
wlp3s0: Request association: reassociate: 0  selected: cc:5d:4e:7a:bb:47  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
wlp3s0: Trying to associate with cc:5d:4e:7a:bb:47 (SSID='SkyNET2.0' freq=2437 MHz)
wlp3s0: Cancelling scan request
wlp3s0: WPA: clearing own WPA/RSN IE
wlp3s0: Automatic auth_alg selection: 0x1
RSN: PMKSA cache search - network_ctx=(nil) try_opportunistic=0
RSN: Search for BSSID cc:5d:4e:7a:bb:47
RSN: No PMKSA cache entry found
wlp3s0: RSN: using IEEE 802.11i/D9.0
wlp3s0: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
wlp3s0: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00
wlp3s0: WPA: using GTK TKIP
wlp3s0: WPA: using PTK CCMP
wlp3s0: WPA: using KEY_MGMT WPA-PSK
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlp3s0: No keys have been configured - skip key clearing
wlp3s0: State: SCANNING -> ASSOCIATING
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
Limit connection to BSSID cc:5d:4e:7a:bb:47 freq=2437 MHz based on scan results (bssid_set=0)
wlp3s0: set_disable_max_amsdu: -1
wlp3s0: set_ampdu_factor: -1
wlp3s0: set_ampdu_density: -1
wlp3s0: set_disable_ht40: 0
wlp3s0: set_disable_sgi: 0
wpa_driver_wext_associate
wpa_driver_wext_set_drop_unencrypted
wpa_driver_wext_set_psk
ioctl[SIOCSIWFREQ]: Device or resource busy
wlp3s0: Association request to the driver failed
wlp3s0: Setting authentication timeout: 5 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP fail=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portControl=Auto
EAPOL: Supplicant port status: Unauthorized
RSN: Ignored PMKID candidate without preauth flag
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=16
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b06 len=12
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b1a len=25
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8c08 len=121
AssocResp IE wireless event - hexdump(len=105): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 2d 1a fc 18 1b ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 06 00 11 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 09 00 10 18 02 00 f0 04 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
Wireless event: cmd=0x8b15 len=24
Wireless event: new AP: cc:5d:4e:7a:bb:47
wlp3s0: Event ASSOCINFO (4) received
wlp3s0: Association info event
resp_ies - hexdump(len=105): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 2d 1a fc 18 1b ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 06 00 11 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 09 00 10 18 02 00 f0 04 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
wlp3s0: Event ASSOC (0) received
wlp3s0: State: ASSOCIATING -> ASSOCIATED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
wlp3s0: Associated to a new BSS: BSSID=cc:5d:4e:7a:bb:47
wlp3s0: No keys have been configured - skip key clearing
wlp3s0: Associated with cc:5d:4e:7a:bb:47
wlp3s0: WPA: Association event - clear replay counter
wlp3s0: WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
wlp3s0: Setting authentication timeout: 10 sec 0 usec
wlp3s0: Cancelling scan request
wlp3s0: RX EAPOL from cc:5d:4e:7a:bb:47
wlp3s0: Setting authentication timeout: 10 sec 0 usec
wlp3s0: IEEE 802.1X RX: version=2 type=3 length=117
wlp3s0:   EAPOL-Key type=2
wlp3s0:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlp3s0:   key_length=16 key_data_length=22
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_nonce - hexdump(len=32): 47 f0 63 ba 3a 9a 38 aa 15 11 95 f0 bd f0 74 aa 82 4d a4 2e 84 9c da 6d d1 14 95 c7 a7 11 40 59
  key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlp3s0: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlp3s0: WPA: RX message 1 of 4-Way Handshake from cc:5d:4e:7a:bb:47 (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 9d 67 62 7e a4 e0 d1 60 8c 59 0d b6 82 66 11 d5
WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 9d 67 62 7e a4 e0 d1 60 8c 59 0d b6 82 66 11 d5
RSN: PMKID from Authenticator - hexdump(len=16): 9d 67 62 7e a4 e0 d1 60 8c 59 0d b6 82 66 11 d5
wlp3s0: RSN: no matching PMKID found
WPA: Renewed SNonce - hexdump(len=32): 8d 1a 1d e4 ae 91 18 64 b6 78 f9 ec a4 09 98 20 fa 61 c0 a1 18 77 2b a8 4a 2b 73 01 28 af a0 f6
WPA: PTK derivation - A1=60:36:dd:7e:1b:0c A2=cc:5d:4e:7a:bb:47
WPA: Nonce1 - hexdump(len=32): 8d 1a 1d e4 ae 91 18 64 b6 78 f9 ec a4 09 98 20 fa 61 c0 a1 18 77 2b a8 4a 2b 73 01 28 af a0 f6
WPA: Nonce2 - hexdump(len=32): 47 f0 63 ba 3a 9a 38 aa 15 11 95 f0 bd f0 74 aa 82 4d a4 2e 84 9c da 6d d1 14 95 c7 a7 11 40 59
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 00
wlp3s0: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 94 1e 01 41 ec f7 3b 67 6f 38 63 6f a2 6c 96 f9
wlp3s0: RX EAPOL from cc:5d:4e:7a:bb:47
wlp3s0: IEEE 802.1X RX: version=2 type=3 length=175
wlp3s0:   EAPOL-Key type=2
wlp3s0:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
wlp3s0:   key_length=16 key_data_length=80
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
  key_nonce - hexdump(len=32): 47 f0 63 ba 3a 9a 38 aa 15 11 95 f0 bd f0 74 aa 82 4d a4 2e 84 9c da 6d d1 14 95 c7 a7 11 40 59
  key_iv - hexdump(len=16): 82 4d a4 2e 84 9c da 6d d1 14 95 c7 a7 11 40 5a
  key_rsc - hexdump(len=8): d8 02 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 5c f9 bc 76 1e e5 a9 99 15 55 f6 16 e0 23 23 63
RSN: encrypted key data - hexdump(len=80): 27 1b 98 63 d2 31 e9 d9 2a 70 c2 4d ea 96 a6 d6 96 43 dc 49 2c f1 05 cb 61 49 f1 1a 0f 6f 75 1a e4 55 6e 84 2d 6c 7e a0 6f 93 9a fb 0a 07 75 bb 12 c1 38 05 68 1f 0b 33 30 0d 5b 52 cd ec a7 37 30 bb 59 16 b1 24 cd 32 b2 09 14 49 5f d2 54 84
WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
wlp3s0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlp3s0: WPA: RX message 3 of 4-Way Handshake from cc:5d:4e:7a:bb:47 (ver=2)
WPA: IE KeyData - hexdump(len=72): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00 dd 26 00 0f ac 01 02 00 25 41 cb 7e 76 ac e9 2f 61 49 79 c4 ba 11 b0 18 d1 24 7f 59 d8 83 7b 23 c3 91 28 f4 cd 6d 02 a1 dd 00 00 00 00 00
WPA: RSN IE in EAPOL-Key - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00
WPA: GTK in EAPOL-Key - hexdump(len=40): [REMOVED]
wlp3s0: WPA: Sending EAPOL-Key 4/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 22 48 89 3b 72 da ad 78 f6 88 b0 9a 37 e3 5f e9
wlp3s0: WPA: Installing PTK to the driver
wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
EAPOL: External notification - portValid=1
wlp3s0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
WPA: Group Key - hexdump(len=32): [REMOVED]
wlp3s0: WPA: Installing GTK to the driver (keyidx=2 tx=0 len=32)
WPA: RSC - hexdump(len=6): d8 02 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=2 set_tx=0 seq_len=6 key_len=32
wlp3s0: WPA: Key negotiation completed with cc:5d:4e:7a:bb:47 [PTK=CCMP GTK=TKIP]
wlp3s0: Cancelling authentication timeout
wlp3s0: State: GROUP_HANDSHAKE -> COMPLETED
wlp3s0: CTRL-EVENT-CONNECTED - Connection to cc:5d:4e:7a:bb:47 completed [id=0 id_str=]
wpa_driver_wext_set_operstate: operstate 0->1 (UP)
netlink: Operstate: linkmode=-1, operstate=6
EAPOL: External notification - portValid=1
EAPOL: External notification - EAP success=1
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state SUCCESS
EAP: EAP entering state DISABLED
EAPOL: SUPP_PAE entering state AUTHENTICATED
EAPOL: Supplicant port status: Authorized
EAPOL: SUPP_BE entering state IDLE
EAPOL authentication completed successfully
RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp3s0' added
WEXT: if_removed already cleared - ignore event
EAPOL: startWhen --> 0
EAPOL: disable timer tick
wlp3s0: BSS: Remove id 1 BSSID 70:71:bc:51:d3:1b SSID '17e855' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 2 BSSID 00:0c:c3:d3:41:cd SSID 'ElisaKoti04' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 3 BSSID e8:40:f2:56:b7:89 SSID 'HannumoiJnen' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 4 BSSID cc:5d:4e:a2:88:6f SSID 'ZyXEL_9444' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 5 BSSID e8:40:f2:50:8a:ec SSID 'f40d53' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 6 BSSID 38:60:77:cc:3c:b6 SSID 'varamies' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 7 BSSID b4:07:f9:1f:77:6b SSID 'Piian puhelin ' due to wpa_bss_flush_by_age
wlp3s0: BSS: Remove id 8 BSSID e8:40:f2:56:0b:05 SSID 'f400c9' due to wpa_bss_flush_by_age


wlp3s0: RX EAPOL from cc:5d:4e:7a:bb:47
wlp3s0: IEEE 802.1X RX: version=2 type=3 length=143
wlp3s0:   EAPOL-Key type=2
wlp3s0:   key_info 0x1382 (ver=2 keyidx=0 rsvd=0 Group Ack MIC Secure Encr)
wlp3s0:   key_length=0 key_data_length=48
  replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
  key_nonce - hexdump(len=32): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  key_iv - hexdump(len=16): 82 4d a4 2e 84 9c da 6d d1 14 95 c7 a7 11 40 5b
  key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
  key_mic - hexdump(len=16): 6f 5a ae eb 87 6c f3 27 8d a9 c6 32 b0 7b 81 ec
RSN: encrypted key data - hexdump(len=48): c8 42 ee 29 04 b6 16 75 b8 97 bc 6f cb 51 d4 24 1b 12 53 0b a3 3a 71 a8 4b b7 88 82 4d 52 50 80 1d 34 2e 03 ce c6 e0 7e 3e 21 8f ea 90 07 57 63
WPA: decrypted EAPOL-Key key data - hexdump(len=40): [REMOVED]
wlp3s0: WPA: RX message 1 of Group Key Handshake from cc:5d:4e:7a:bb:47 (ver=2)
RSN: msg 1/2 key data - hexdump(len=40): dd 26 00 0f ac 01 01 00 fd 83 4c 0a 48 64 c5 7a ef 16 74 36 18 14 ac 8c b1 0d eb 66 ef 0d b3 f5 03 1c 66 a8 cc 06 55 d5
WPA: GTK in EAPOL-Key - hexdump(len=40): [REMOVED]
RSN: received GTK in group key handshake - hexdump(len=34): 01 00 fd 83 4c 0a 48 64 c5 7a ef 16 74 36 18 14 ac 8c b1 0d eb 66 ef 0d b3 f5 03 1c 66 a8 cc 06 55 d5
wlp3s0: State: COMPLETED -> GROUP_HANDSHAKE
WPA: Group Key - hexdump(len=32): [REMOVED]
wlp3s0: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=1 set_tx=0 seq_len=6 key_len=32
wlp3s0: WPA: Sending EAPOL-Key 2/2
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 48 7f c3 67 ed 03 f0 61 49 2b 57 51 67 34 07 b5
wlp3s0: WPA: Group rekeying completed with cc:5d:4e:7a:bb:47 [GTK=TKIP]
wlp3s0: Cancelling authentication timeout
wlp3s0: State: GROUP_HANDSHAKE -> COMPLETED
^Cwlp3s0: Removing interface wlp3s0
wlp3s0: Request to deauthenticate - bssid=cc:5d:4e:7a:bb:47 pending_bssid=00:00:00:00:00:00 reason=3 state=COMPLETED
wpa_driver_wext_deauthenticate
wlp3s0: Event DEAUTH (12) received
wlp3s0: Deauthentication notification
wlp3s0:  * reason 3 (locally generated)
Deauthentication frame IE(s) - hexdump(len=0): [NULL]
wlp3s0: CTRL-EVENT-DISCONNECTED bssid=cc:5d:4e:7a:bb:47 reason=3 locally_generated=1
wlp3s0: Auto connect enabled: try to reconnect (wps=0 wpa_state=9)
wlp3s0: Setting scan request: 0 sec 100000 usec
Added BSSID cc:5d:4e:7a:bb:47 into blacklist
wlp3s0: Blacklist count 1 --> request scan in 100 ms
wlp3s0: Setting scan request: 0 sec 100000 usec
wlp3s0: Disconnect event - remove keys
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
wlp3s0: State: COMPLETED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: Supplicant port status: Unauthorized
EAPOL: SUPP_BE entering state INITIALIZE
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
wlp3s0: No keys have been configured - skip key clearing
wlp3s0: State: DISCONNECTED -> DISCONNECTED
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
wpa_driver_wext_set_countermeasures
wlp3s0: No keys have been configured - skip key clearing
Removed BSSID cc:5d:4e:7a:bb:47 from blacklist (clear)
wlp3s0: BSS: Remove id 0 BSSID cc:5d:4e:7a:bb:47 SSID 'SkyNET2.0' due to wpa_bss_flush
wlp3s0: Cancelling scan request
wlp3s0: Cancelling authentication timeout
netlink: Operstate: linkmode=0, operstate=6
wlp3s0: CTRL-EVENT-TERMINATING

the sad clown · 2013-02-18 22:02:04

Try 'pkill wpa_supplicant' to make sure there are no instances of it running, then run it again and see if it improves your situation. Also, if you are going to use dhclient, make sure there are no instances of dhcpcd running or duplicant instances of dhclient.

You can check this with either top or 'ps -ef'.

Last edited by the sad clown (2013-02-18 22:24:15)

raskug · 2013-02-20 23:00:11

Nope. No duplicates of dhclient/dhcpcd/wpa_supplicant running confirmed, but the issue persists.

Arch Linux

#1 2013-02-05 22:26:29

Wireless randomly refuses connections

#2 2013-02-06 01:41:38

Re: Wireless randomly refuses connections

#3 2013-02-06 14:51:59

Re: Wireless randomly refuses connections

#4 2013-02-14 19:31:15

Re: Wireless randomly refuses connections

#5 2013-02-14 19:41:44

Re: Wireless randomly refuses connections

#6 2013-02-15 17:55:58

Re: Wireless randomly refuses connections

#7 2013-02-15 18:24:19

Re: Wireless randomly refuses connections

#8 2013-02-18 17:25:05

Re: Wireless randomly refuses connections

#9 2013-02-18 22:02:04

Re: Wireless randomly refuses connections

#10 2013-02-20 23:00:11

Re: Wireless randomly refuses connections

Board footer