Dear NetworkManager folks,
using Debian Wheezy with the packages network-manager 0.9.0-10 and
wpasupplicant 1.0-3+b1 and a Realtek RTL8188CUS based USB WLAN device,
$ uname -a
Linux myhostname 3.2.0-4-686-pae #1 SMP Debian 3.2.41-2 i686 GNU/Linux
$ lsusb
[…]
Bus 001 Device 005: ID 7392:7811 Edimax Technology Co., Ltd EW-7811Un 802.11n Wireless Adapter
[Realtek RTL8188CUS]
no connection can be established to the wireless network and I am just
asked for the password again and again.
Using a Ralink RT2870 based USB device it works without problems though.
$ lsusb
[…]
Bus 001 Device 004: ID 148f:2870 Ralink Technology, Corp. RT2870 Wireless Adapter
As I am seeing the warning
<warn> Activation (wlan1/wireless): association took too long.
in `/var/log/syslog`, can I avoid recompiling the binary to increase the
timeout from 25 seconds to some higher value as mentioned in thread [1]?
Could such a value be changed in the binary file directly?
Following the debugging instructions [2], here are the corresponding log
messages.
$ more /var/log/wpa_supplicant.log
1368966542.477301: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966542.572504: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966562.574647: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966592.573388: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966594.068594: ssid - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966594.068718: PSK (ASCII passphrase) - hexdump_ascii(len=19): [REMOVED]
1368966594.126895: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966594.127300: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966594.127344: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966594.915272: * SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966594.939713: * SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966607.002248: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966607.002595: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966607.002660: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966607.778985: * SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966607.807021: * SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966618.872864: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966618.923460: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966618.923501: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966662.439126: ssid - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966662.439243: PSK (ASCII passphrase) - hexdump_ascii(len=19): [REMOVED]
1368966662.494369: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966662.494957: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966662.495230: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966668.272739: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966668.273171: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966668.273247: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966674.050499: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966674.050922: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966674.050993: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966679.826592: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966679.827030: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966679.827101: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1368966685.607343: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966685.607777: nl80211: Scan SSID - hexdump_ascii(len=13):
54 49 4d 55 4e 44 53 54 52 55 50 50 49 MYWLAN
1368966685.607853: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
$ more /var/log/syslog
[…]
May 19 14:30:07 mattotaupa wpa_supplicant[5542]: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00
00 00 02
May 19 14:30:07 mattotaupa wpa_supplicant[5542]: wlan1: WPA: Sending EAPOL-Key 2/4
May 19 14:30:07 mattotaupa wpa_supplicant[5542]: WPA: KCK - hexdump(len=16): [REMOVED]
May 19 14:30:07 mattotaupa wpa_supplicant[5542]: WPA: Derived Key MIC - hexdump(len=16): b3 e4 eb 1f
ee ea 39 45 61 01 ed 75 34 f2 7f 24
May 19 14:30:07 mattotaupa wpa_supplicant[5542]: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02
01 0a 00 00 00 00 00 00 00 00 00 02 a5 81 7e 9d 88 b0 0a ef fd 49 51 5e f6 59 db b1 33 cb 92 4e 26 d7 dc 54
71 6e b4 fb 29 06 05 73 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 b3 e4 eb 1f ee ea 39 45 61 01 ed 75 34 f2 7f 24 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04
01 00 00 0f ac 02 00 00
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: EAPOL: startWhen --> 0
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: EAPOL: disable timer tick
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: EAPOL: SUPP_PAE entering state CONNECTING
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: EAPOL: enable timer tick
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: EAPOL: txStart
May 19 14:30:08 mattotaupa wpa_supplicant[5542]: WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1
len=0)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Authentication with bc:05:43:ae:b5:a3 timed
out.
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: Added BSSID bc:05:43:ae:b5:a3 into blacklist
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_disassociate
May 19 14:30:17 mattotaupa kernel: [ 346.262447] wlan1: disassociating from bc:05:43:ae:b5:a3 by
local choice (reason=3)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: No keys have been configured - skip key
clearing
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: State: 4WAY_HANDSHAKE -> DISCONNECTED
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_operstate: operstate 0->0
(DORMANT)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: netlink: Operstate: linkmode=-1, operstate=5
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portEnabled=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: SUPP_PAE entering state DISCONNECTED
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: SUPP_BE entering state INITIALIZE
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portValid=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - EAP success=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Setting scan request: 1 sec 0 usec
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Event message available
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: MLME event 40
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: MLME event frame - hexdump(len=26): a0 00
00 00 bc 05 43 ae b5 a3 80 1f 02 7c de 7b bc 05 43 ae b5 a3 00 00 03 00
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Event DISASSOC (1) received
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Disassociation notification
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: * reason 3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: * address bc:05:43:ae:b5:a3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: Disassociation frame IE(s) - hexdump(len=0): [NULL]
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: SME: Disassociation event received
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: SME: Deauthenticate to clear driver state
May 19 14:30:17 mattotaupa wpa_supplicant[5542]:
wpa_driver_nl80211_deauthenticate(addr=bc:05:43:ae:b5:a3 reason_code=3)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: WPA: Auto connect enabled: try to reconnect
(wps=0)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: Added BSSID 00:00:00:00:00:00 into blacklist
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Not rescheduling scan to ensure that specific
SSID scans occur
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: CTRL-EVENT-DISCONNECTED
bssid=00:00:00:00:00:00 reason=3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Disconnect event - remove keys
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=0x8651734 key_idx=0 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: addr=00:00:00:00:00:00
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: State: DISCONNECTED -> DISCONNECTED
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_operstate: operstate 0->0
(DORMANT)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: netlink: Operstate: linkmode=-1, operstate=5
May 19 14:30:17 mattotaupa kernel: [ 346.300721] cfg80211: Calling CRDA to update world regulatory
domain
May 19 14:30:17 mattotaupa kernel: [ 346.302708] wlan1: deauthenticating from bc:05:43:ae:b5:a3 by
local choice (reason=3)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portEnabled=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portValid=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - EAP success=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: if_removed already cleared - ignore event
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: if_removed already cleared - ignore event
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Event message available
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Ignore disconnect event when using
userspace SME
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Event message available
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Delete station bc:05:43:ae:b5:a3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: Event message available
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: MLME event 39
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: nl80211: MLME event frame - hexdump(len=26): c0 00
00 00 bc 05 43 ae b5 a3 80 1f 02 7c de 7b bc 05 43 ae b5 a3 00 00 03 00
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Event DEAUTH (12) received
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Deauthentication notification
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: * reason 3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: * address bc:05:43:ae:b5:a3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: Deauthentication frame IE(s) - hexdump(len=0): [NULL]
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: WPA: Auto connect enabled: try to reconnect
(wps=0)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: BSSID 00:00:00:00:00:00 blacklist count incremented
to 2
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Not rescheduling scan to ensure that specific
SSID scans occur
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: CTRL-EVENT-DISCONNECTED
bssid=00:00:00:00:00:00 reason=3
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: Disconnect event - remove keys
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_key: ifindex=5 alg=0
addr=0x8651734 key_idx=0 set_tx=0 seq_len=0 key_len=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: addr=00:00:00:00:00:00
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wlan1: State: DISCONNECTED -> DISCONNECTED
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: wpa_driver_nl80211_set_operstate: operstate 0->0
(DORMANT)
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: netlink: Operstate: linkmode=-1, operstate=5
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portEnabled=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - portValid=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: External notification - EAP success=0
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:17 mattotaupa wpa_supplicant[5542]: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
May 19 14:30:17 mattotaupa NetworkManager[2765]: <info> (wlan1): supplicant interface state: 4-way
handshake -> disconnected
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: wlan1: State: DISCONNECTED -> SCANNING
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: wlan1: Starting AP scan for wildcard SSID
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: Scan requested (ret=0) - scan timeout 30 seconds
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: nl80211: Event message available
May 19 14:30:18 mattotaupa wpa_supplicant[5542]: nl80211: Scan trigger
May 19 14:30:18 mattotaupa NetworkManager[2765]: <info> (wlan1): supplicant interface state:
disconnected -> scanning
May 19 14:30:19 mattotaupa wpa_supplicant[5542]: EAPOL: Supplicant port status: Unauthorized
May 19 14:30:19 mattotaupa NetworkManager[2765]: <warn> Activation (wlan1/wireless): association took
too long.
May 19 14:30:19 mattotaupa NetworkManager[2765]: <info> (wlan1): device state change: config ->
need-auth (reason 'none') [50 60 0]
[…]
Any idea, what might be going wrong here?
Thanks,
Paul
[1] https://mail.gnome.org/archives/networkmanager-list/2011-April/msg00193.html
[2] https://live.gnome.org/NetworkManager/Debugging
Attachment:
20130519--nm.syslog.7z
Description: application/7z-compressed
Attachment:
signature.asc
Description: This is a digitally signed message part