Hi, I cannot connect to a wireless network, because network manager says that association took too long. I can imagine, that this is not a fault of network manager, but you can at lest forward me to somebody else.
I'm using vanilla Linux 2.6.37.4 and I have the following WiFi NIC: 10:00.0 Network controller: Intel Corporation PRO/Wireless 3945ABG [Golan] Network Connection (rev 02) I found some old bug reports, similar to my problem, and the problem there was caused by buggy drivers. I do not think this is my case, because I can connect to almost every wireless network expect a single one - Eduroam (http://www.eduroam.org/). The problem appears only when I'm abroad so I wonder whether the network manager's timeout (25 seconds) elapses because the authentication between different countries takes long time due to a slower connection to authentication servers. By applying the following patch, I'm able to connect: diff --git a/src/nm-device-wifi.c b/src/nm-device-wifi.c index 9258f77..032113b 100644 --- a/src/nm-device-wifi.c +++ b/src/nm-device-wifi.c @@ -2828,7 +2828,7 @@ start_supplicant_connection_timeout (NMDeviceWifi *self) priv = NM_DEVICE_WIFI_GET_PRIVATE (self); /* Set up a timeout on the connection attempt to fail it after 25 seconds */ - id = g_timeout_add_seconds (25, supplicant_connection_timeout_cb, self); + id = g_timeout_add_seconds (60, supplicant_connection_timeout_cb, self); if (id == 0) { nm_log_err (LOGD_DEVICE | LOGD_WIFI, "Activation (%s/wireless): couldn't start supplicant " Then, the log of successfull connection process is attached bellow and one can see which part takes how long. It seems that wpa_suplicant is the one to blame, but it might be that there is no way to achieve faster authentication because of poor network connectivity to the authentication server. Can someone confirm, that this hypothesis is correct? And if it is, what should network manager users do when they do not want to patch and recompile network manager? Thanks Michal Apr 26 20:00:06 steelpick NetworkManager[25803]: <info> WiFi now enabled by radio killswitch Apr 26 20:00:06 steelpick NetworkManager[25803]: <info> (wlan0): bringing up device. Apr 26 20:00:06 steelpick NetworkManager[25803]: <info> (wlan0): supplicant interface state: starting -> ready Apr 26 20:00:06 steelpick NetworkManager[25803]: <info> (wlan0): device state change: 2 -> 3 (reason 42) Apr 26 20:00:06 steelpick wpa_supplicant[2503]: Failed to initiate AP scan. Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) starting connection 'Auto eduroam' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> (wlan0): device state change: 3 -> 4 (reason 0) Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> (wlan0): device state change: 4 -> 5 (reason 0) Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0/wireless): connection 'Auto eduroam' has security, and secrets exist. No new secrets needed. Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'ssid' value 'eduroam' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'scan_ssid' value '1' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'key_mgmt' value 'WPA-EAP' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'password' value '<omitted>' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'eap' value 'PEAP' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'fragment_size' value '1300' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'phase2' value 'auth=MSCHAPV2' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'ca_cert' value '/etc/ssl/certs/cesnet-ca.cz.pem' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: added 'identity' value '[email protected]' Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Apr 26 20:00:09 steelpick NetworkManager[25803]: <info> Config: set interface ap_scan to 1 Apr 26 20:00:16 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: inactive -> scanning Apr 26 20:00:19 steelpick wpa_supplicant[2503]: Trying to associate with 08:17:35:82:f6:7d (SSID='eduroam' freq=5520 MHz) Apr 26 20:00:19 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: scanning -> associating Apr 26 20:00:19 steelpick wpa_supplicant[2503]: Associated with 08:17:35:82:f6:7d Apr 26 20:00:19 steelpick wpa_supplicant[2503]: CTRL-EVENT-EAP-STARTED EAP authentication started Apr 26 20:00:19 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: associating -> associated Apr 26 20:00:21 steelpick avahi-daemon[2242]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::21f:3cff:fedf:1e2a. Apr 26 20:00:21 steelpick avahi-daemon[2242]: New relevant interface wlan0.IPv6 for mDNS. Apr 26 20:00:21 steelpick avahi-daemon[2242]: Registering new address record for fe80::21f:3cff:fedf:1e2a on wlan0.*. Apr 26 20:00:49 steelpick wpa_supplicant[2503]: CTRL-EVENT-EAP-STARTED EAP authentication started Apr 26 20:00:49 steelpick wpa_supplicant[2503]: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected Apr 26 20:00:49 steelpick wpa_supplicant[2503]: EAP-MSCHAPV2: Authentication succeeded Apr 26 20:00:49 steelpick wpa_supplicant[2503]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed Apr 26 20:00:49 steelpick wpa_supplicant[2503]: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: associated -> 4-way handshake Apr 26 20:00:49 steelpick wpa_supplicant[2503]: WPA: Key negotiation completed with 08:17:35:82:f6:7d [PTK=CCMP GTK=TKIP] Apr 26 20:00:49 steelpick wpa_supplicant[2503]: CTRL-EVENT-CONNECTED - Connection to 08:17:35:82:f6:7d completed (auth) [id=0 id_str=] Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: 4-way handshake -> group handshake Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> (wlan0): supplicant connection state: group handshake -> completed Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'eduroam'. Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> (wlan0): device state change: 5 -> 7 (reason 0) Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> Activation (wlan0) Beginning DHCPv4 transaction (timeout in 45 seconds) Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> dhclient started with pid 26280 Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete. Apr 26 20:00:49 steelpick dhclient: Internet Systems Consortium DHCP Client 4.1.1-P1 Apr 26 20:00:49 steelpick dhclient: Copyright 2004-2010 Internet Systems Consortium. Apr 26 20:00:49 steelpick dhclient: All rights reserved. Apr 26 20:00:49 steelpick dhclient: For info, please visit https://www.isc.org/software/dhcp/ Apr 26 20:00:49 steelpick dhclient: Apr 26 20:00:49 steelpick NetworkManager[25803]: <info> (wlan0): DHCPv4 state changed nbi -> preinit Apr 26 20:00:49 steelpick dhclient: Listening on LPF/wlan0/00:1f:3c:df:1e:2a Apr 26 20:00:49 steelpick dhclient: Sending on LPF/wlan0/00:1f:3c:df:1e:2a Apr 26 20:00:49 steelpick dhclient: Sending on Socket/fallback Apr 26 20:00:51 steelpick dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 Apr 26 20:00:58 steelpick dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 Apr 26 20:00:58 steelpick dhclient: DHCPACK from 141.30.1.225 Apr 26 20:00:58 steelpick dhclient: bound to 141.76.185.8 -- renewal in 236 seconds. Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> (wlan0): DHCPv4 state changed preinit -> reboot Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) scheduled... Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) started... Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> address 141.76.185.8 Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> prefix 22 (255.255.252.0) Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> gateway 141.76.184.1 Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> nameserver '141.30.66.135' Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> nameserver '141.30.66.1' Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> domain name 'dip.tu-dresden.de' Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Scheduling stage 5 Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled... Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Done scheduling stage 5 Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 4 of 5 (IP4 Configure Get) complete. Apr 26 20:00:58 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started... Apr 26 20:00:58 steelpick avahi-daemon[2242]: Joining mDNS multicast group on interface wlan0.IPv4 with address 141.76.185.8. Apr 26 20:00:58 steelpick avahi-daemon[2242]: New relevant interface wlan0.IPv4 for mDNS. Apr 26 20:00:58 steelpick avahi-daemon[2242]: Registering new address record for 141.76.185.8 on wlan0.IPv4. Apr 26 20:00:59 steelpick NetworkManager[25803]: <info> (wlan0): device state change: 7 -> 8 (reason 0) Apr 26 20:00:59 steelpick NetworkManager[25803]: <info> Policy set 'Auto eduroam' (wlan0) as default for IPv4 routing and DNS. Apr 26 20:00:59 steelpick NetworkManager[25803]: <info> Activation (wlan0) successful, device activated. Apr 26 20:00:59 steelpick NetworkManager[25803]: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete. Apr 26 20:00:59 steelpick ntpdate[26321]: the NTP socket is in use, exiting _______________________________________________ networkmanager-list mailing list [email protected] http://mail.gnome.org/mailman/listinfo/networkmanager-list
