After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 558175 - Connection to 'Eduroam' 802.1x EAP-TTLS (RADIUS) secured wireless network fails
Connection to 'Eduroam' 802.1x EAP-TTLS (RADIUS) secured wireless network fails
Status: RESOLVED INCOMPLETE
Product: NetworkManager
Classification: Platform
Component: general
git master
Other Linux
: Normal normal
: ---
Assigned To: Dan Williams
Dan Williams
Depends on:
Blocks:
 
 
Reported: 2008-10-27 23:45 UTC by Robin Dickhaut
Modified: 2010-03-24 18:05 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
NM sucesseful connection log (18.32 KB, text/plain)
2009-02-26 09:43 UTC, Luis Medinas
Details

Description Robin Dickhaut 2008-10-27 23:45:53 UTC
I can't get NetworkManager/nm-applet to connect to the Eduroam network (802.1x EAP-TTLS (RADIUS) secured; also see http://www.eduroam.org/) at my university. While manual connection with wpa_supplicant is working perfectly, I keep getting timeouts with NetworkManager:


NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  (eth1): device state change: 6 -> 4
NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (eth1): device state change: 4 -> 5
NetworkManager: <info>  Activation (eth1/wireless): connection 'Auto eduroam' has security, and secrets exist.  No new secrets needed.
NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
NetworkManager: <info>  Config: added 'scan_ssid' value '1'
NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
NetworkManager: <info>  Config: added 'proto' value 'WPA RSN'
NetworkManager: <info>  Config: added 'pairwise' value 'TKIP CCMP'
NetworkManager: <info>  Config: added 'group' value 'WEP40 WEP104 TKIP CCMP'
NetworkManager: <info>  Config: added 'password' value '<omitted>'
NetworkManager: <info>  Config: added 'eap' value 'TTLS'
NetworkManager: <info>  Config: added 'fragment_size' value '1300'
NetworkManager: <info>  Config: added 'phase2' value 'auth=PAP'
NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-NetworkManagerSettings-3-ca_cert'
NetworkManager: <info>  Config: added 'identity' value 'xxx.xxx@campus.lmu.de'
NetworkManager: <info>  Config: added 'anonymous_identity' value 'anonymous@mwn.de'
NetworkManager: <info>  Activation (eth1) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Config: set interface ap_scan to 1
NetworkManager: <info>  (eth1): supplicant connection state change: 0 -> 2
NetworkManager: <info>  (eth1): supplicant connection state change: 2 -> 3
NetworkManager: <info>  (eth1): supplicant connection state change: 3 -> 0
NetworkManager: <info>  (eth1): supplicant connection state change: 0 -> 4
NetworkManager: <info>  (eth1): supplicant connection state change: 4 -> 3
NetworkManager: <info>  (eth1): supplicant connection state change: 3 -> 0
NetworkManager: <info>  (eth1): supplicant connection state change: 0 -> 4
NetworkManager: <info>  eth1: link timed out.
NetworkManager: <info>  Activation (eth1/wireless): association took too long.
NetworkManager: <info>  (eth1): device state change: 5 -> 6
NetworkManager: <info>  Activation (eth1/wireless): asking for new secrets
NetworkManager: <info>  (eth1): supplicant connection state change: 4 -> 0
NetworkManager: <info>  eth1: link timed out.



I'm using network-manager 0.7~~svn20081018t105859-0ubuntu1 on Ubuntu Intrepid.

Here's a tarball containing the outputs of NetworkManager and iwevent, and my working wpa_supplicant config. Just let me know if anything else is needed, I'd be glad to provide you with additional information.
http://www.cip.ifi.lmu.de/~dickhaut/NetworkManager_eduroam_logs.tar.gz


Best regards,
Robin
Comment 1 Luis Medinas 2008-11-25 15:16:47 UTC
I can confirm the bug in University of Aveiro - Portugal using the same "eduroam" network.

It worked on NM 0.6. 
Comment 2 Luis Medinas 2008-11-28 16:36:38 UTC
Add networkmanager log.

Nov 28 14:31:17 linux-8dhw NetworkManager: <info>  (eth0): device state change: 3 -> 2
Nov 28 14:31:17 linux-8dhw NetworkManager: <info>  (eth0): deactivating device (reason: 40).
Nov 28 14:31:17 linux-8dhw NetworkManager: <WARN>  auto_activate_device(): Connection 'System eth0' auto-activation failed: (2) Device not managed by NetworkManager
Nov 28 14:31:17 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 2 -> 3
Nov 28 14:31:17 linux-8dhw NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) starting connection 'Auto eduroam'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 3 -> 4
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto eduroam' has security, and secrets exist.  No new secrets needed.
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'password' value '<omitted>'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'eap' value 'PEAP'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'fragment_size' value '1300'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'phase1' value 'peapver=1'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'phase2' value 'auth=MSCHAPV2'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-NetworkManagerSettings-2-ca_cert'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: added 'identity' value 'lmedinas@ua.pt'
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  Config: set interface ap_scan to 1
Nov 28 14:33:04 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  inactive -> scanning
Nov 28 14:33:07 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associating
Nov 28 14:33:09 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associated
Nov 28 14:33:29 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): association took too long.
Nov 28 14:33:29 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 5 -> 6
Nov 28 14:33:29 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): asking for new secrets
Nov 28 14:33:29 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:30 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:30 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:31 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:31 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:33 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:33 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:34 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:34 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:35 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:35 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:36 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:36 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:37 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> associated
Nov 28 14:33:37 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:37 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
Nov 28 14:33:38 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
Nov 28 14:33:38 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> disconnected
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 6 -> 4
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto eduroam' has security, and secrets exist.  No new secrets needed.
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'password' value '<omitted>'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'eap' value 'PEAP'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'fragment_size' value '1300'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'phase1' value 'peapver=1'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'phase2' value 'auth=MSCHAPV2'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-NetworkManagerSettings-2-ca_cert'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: added 'identity' value 'lmedinas@ua.pt'
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  Config: set interface ap_scan to 1
Nov 28 14:33:39 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
Nov 28 14:33:40 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associating
Nov 28 14:33:53 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> disconnected
Nov 28 14:33:53 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
Nov 28 14:33:55 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associating
Nov 28 14:34:04 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): association took too long.
Nov 28 14:34:04 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 5 -> 6
Nov 28 14:34:04 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): asking for new secrets
Nov 28 14:34:04 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> disconnected
Nov 28 14:34:06 linux-8dhw NetworkManager: <WARN>  get_secrets_cb(): Couldn't get connection secrets: applet-device-wifi.c.1537 (get_secrets_dialog_response_cb): canceled.
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 6 -> 9
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  Activation (wlan0) failed for access point (eduroam)
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  Marking connection 'Auto eduroam' invalid.
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  Activation (wlan0) failed.
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 9 -> 3
Nov 28 14:34:06 linux-8dhw NetworkManager: <info>  (wlan0): deactivating device (reason: 0).
Nov 28 14:34:16 linux-8dhw NetworkManager: <WARN>  nm_signal_handler(): Caught signal 15, shutting down normally.
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (eth0): now unmanaged
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (eth0): device state change: 2 -> 1
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (eth0): cleaning up...
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (eth0): taking down device.
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (wlan0): now unmanaged
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 3 -> 1
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (wlan0): cleaning up...
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  (wlan0): taking down device.
Nov 28 14:34:16 linux-8dhw NetworkManager: <info>  disconnected by the system bus.
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  starting...
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  Trying to start the modem-manager...
Nov 28 15:57:10 linux-8dhw NetworkManager: <WARN>  nm_generic_enable_loopback(): error -17 returned from rtnl_addr_add(): Sucess
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  eth0: driver is 'sky2'.
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  Found new Ethernet device 'eth0'.
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  (eth0): exported as /org/freedesktop/Hal/devices/net_00_19_e3_36_98_eb
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  wlan0: driver is 'ath9k'.
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  wlan0: driver supports SSID scans (scan_capa 0x01).
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  Found new 802.11 WiFi device 'wlan0'.
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  (wlan0): exported as /org/freedesktop/Hal/devices/net_00_19_e3_d8_2b_7c
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  Trying to start the supplicant...
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  Trying to start the system settings daemon...
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  (wlan0): supplicant manager state:  down -> idle
Nov 28 15:57:10 linux-8dhw NetworkManager: <info>  modem manager appeared
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): device state change: 1 -> 2
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): bringing up device.
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): preparing device.
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): deactivating device (reason: 2).
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 1 -> 2
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): bringing up device.
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): preparing device.
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): deactivating device (reason: 2).
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): carrier now ON (device state 2)
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): device state change: 2 -> 3
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): carrier now OFF (device state 3)
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): device state change: 3 -> 2
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (eth0): deactivating device (reason: 40).
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 2 -> 3
Nov 28 15:57:14 linux-8dhw NetworkManager: <WARN>  auto_activate_device(): Connection 'System eth0' auto-activation failed: (2) Device not managed by NetworkManager
Nov 28 15:57:14 linux-8dhw NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
Nov 28 15:57:58 linux-8dhw NetworkManager: <info>  Activation (wlan0) starting connection 'Auto eduroam'
Nov 28 15:57:58 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 3 -> 4
Nov 28 15:57:58 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.


Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0/wireless): access point 'Auto eduroam' has security, but secrets are required.
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 5 -> 6
Nov 28 15:58:00 linux-8dhw NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Nov 28 15:58:04 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  inactive -> scanning
Nov 28 15:58:11 linux-8dhw NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> inactive
Nov 28 15:58:13 linux-8dhw NetworkManager: <WARN>  get_secrets_cb(): Couldn't get connection secrets: applet-device-wifi.c.1537 (get_secrets_dialog_response_cb): canceled.
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 6 -> 9
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  Activation (wlan0) failed for access point (eduroam)
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  Marking connection 'Auto eduroam' invalid.
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  Activation (wlan0) failed.
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 9 -> 3
Nov 28 15:58:13 linux-8dhw NetworkManager: <info>  (wlan0): deactivating device (reason: 0).
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  (wlan0): supplicant manager state:  idle -> down
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 3 -> 2
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  (wlan0): deactivating device (reason: 10).
Nov 28 15:59:46 linux-8dhw NetworkManager: supplicant_interface_acquire: assertion `mgr_state == NM_SUPPLICANT_MANAGER_STATE_IDLE' failed
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  Trying to start the supplicant...
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  (wlan0): supplicant manager state:  down -> idle
Nov 28 15:59:46 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 2 -> 3
Nov 28 15:59:47 linux-8dhw NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
Nov 28 15:59:53 linux-8dhw NetworkManager: <WARN>  nm_signal_handler(): Caught signal 15, shutting down normally.
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (eth0): now unmanaged
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (eth0): device state change: 2 -> 1
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (eth0): cleaning up...
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (eth0): taking down device.
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (wlan0): now unmanaged
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (wlan0): device state change: 3 -> 1
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (wlan0): cleaning up...
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  (wlan0): taking down device.
Nov 28 15:59:53 linux-8dhw NetworkManager: <info>  disconnected by the system bus.
Comment 3 Luis Medinas 2009-01-13 23:57:24 UTC
This issue is fixed for me now i'm able to connect to Eduroam network. I'm using NM from opensuse 11.1.
Comment 4 Dan Williams 2009-01-16 20:00:13 UTC
Ok, thanks for the update.
Comment 5 Luis Medinas 2009-02-06 03:00:42 UTC
Dan reopenning...

I can connect but the connection is over (timeout) after just a few minutes.Sometimes i also have lot's of trouble connecting to this Network. This worked with NM 0.6 lot's of people here is falling back to distros that shipped NM 0.6 i belive there is also a bug opened on redhat bugzilla

Please say what logs you need and i'll add them asap.

Thanks
Comment 6 Luis Medinas 2009-02-06 03:05:20 UTC
This friend of mine (here at the university with the same network) has problems related with this one:

https://bugzilla.redhat.com/show_bug.cgi?id=428591
https://bugzilla.redhat.com/show_bug.cgi?id=445369
Comment 7 Dan Williams 2009-02-06 16:48:05 UTC
Can you grab some wpa_supplicant output for me?

Add "-dddt" to the end of the "Exec=" line in /usr/share/dbus-1/system-services/fi.epitest.hostap.WPASupplicant.service and then "killall -TERM wpa_supplicant", reconnect, and you'll get a lot of output in /var/log/wpa_supplicant.log.  That's what I need.

If the connection doesn't last long, that seems like the driver isn't able to reconnect or rekey within a reasonable timeframe, and the connection drops.  Let's see what is happening in the supplicant.
Comment 8 Dan Williams 2009-02-06 21:50:57 UTC
Can I get some 'iwlist wlan0 scan' output for your Eduroam AP too?
Comment 9 Luis Medinas 2009-02-09 13:57:41 UTC
wlan0     Scan completed :
          Cell 01 - Address: 00:1F:CA:2C:61:90
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:6
                    Frequency:2.437 GHz (Channel 6)
                    Quality=37/100  Signal level:-71 dBm  Noise level=-95 dBm
                    Encryption key:off
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003dcc54970f2
                    Extra: Last beacon: 4228ms ago
          Cell 02 - Address: 00:0F:24:D1:5F:C0
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:6
                    Frequency:2.437 GHz (Channel 6)
                    Quality=60/100  Signal level:-56 dBm  Noise level=-95 dBm
                    Encryption key:off
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003ddbd3c70e9
                    Extra: Last beacon: 16ms ago
          Cell 03 - Address: 00:0C:F6:19:EA:D9
                    ESSID:"Sitecom"
                    Mode:Master
                    Channel:11
                    Frequency:2.462 GHz (Channel 11)
                    Quality=23/100  Signal level:-80 dBm  Noise level=-95 dBm
                    Encryption key:off
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s; 6 Mb/s
                              9 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000000379063c16f
                    Extra: Last beacon: 1528ms ago
          Cell 04 - Address: 00:0F:24:D6:9E:F0
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:11
                    Frequency:2.462 GHz (Channel 11)
                    Quality=50/100  Signal level:-63 dBm  Noise level=-95 dBm
                    Encryption key:off
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003ddbdc14101
                    Extra: Last beacon: 1536ms ago
          Cell 05 - Address: 00:0F:24:D6:C5:60
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=46/100  Signal level:-65 dBm  Noise level=-95 dBm
                    Encryption key:on
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003ddbe066a4f
                    Extra: Last beacon: 2140ms ago
          Cell 06 - Address: 00:1F:9E:C0:D4:60
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=34/100  Signal level:-73 dBm  Noise level=-95 dBm
                    Encryption key:on
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003dcc5da3c03
                    Extra: Last beacon: 2140ms ago
          Cell 07 - Address: 00:1F:CA:2C:F8:D0
                    ESSID:"eduroam"
                    Mode:Master
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=34/100  Signal level:-73 dBm  Noise level=-95 dBm
                    Encryption key:on
                    IE: WPA Version 1
                        Group Cipher : TKIP
                        Pairwise Ciphers (1) : TKIP
                        Authentication Suites (1) : 802.1x
                    Bit Rates:11 Mb/s; 12 Mb/s; 18 Mb/s; 24 Mb/s; 36 Mb/s
                              48 Mb/s; 54 Mb/s
                    Extra:tsf=000003dcc4a031a2
                    Extra: Last beacon: 2140ms ago
          Cell 08 - Address: 56:10:78:62:39:C6
                    ESSID:"Wifi USB"
                    Mode:Ad-Hoc
                    Channel:1
                    Frequency:2.412 GHz (Channel 1)
                    Quality=28/100  Signal level:-77 dBm  Noise level=-95 dBm
                    Encryption key:off
                    Bit Rates:1 Mb/s; 2 Mb/s; 5.5 Mb/s; 11 Mb/s
                    Extra:tsf=00000000022fd298
                    Extra: Last beacon: 4508ms ago
Comment 10 Luis Medinas 2009-02-09 15:04:36 UTC
Sorry Dan i couldn't reconnect after getting that change i'll try later.
The main problem is  that we can't get at least 50% sucesseful connects and if it's connected the connection goes down after a few minutes connected.
Comment 11 Dan Williams 2009-02-09 17:44:18 UTC
(In reply to comment #10)
> Sorry Dan i couldn't reconnect after getting that change i'll try later.
> The main problem is  that we can't get at least 50% sucesseful connects and if
> it's connected the connection goes down after a few minutes connected.

Yeah, this is more of a supplicant and driver problem since the driver is loosing association to the network.  Would be good to get some logs from the supplicant (and kernel potentially) as to why the connection is dropping at a driver level.  Increasing supplicant debugging here would be useful.  Add "-dddt" to the end of the Exec= line in /usr/share/dbus-1/system-services/fi.epitest.hostap.WPASupplicant.service and then as root 'killall -TERM wpa_supplicant', which should start verbose logging to /var/log/wpa_supplicant.log, depending on how your distro has set up the logging in wpa_supplicant.
Comment 12 Luis Medinas 2009-02-26 09:41:57 UTC
Ok here's the debug sorry for the delay

Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 26 09:30:45 dirac NetworkManager: <info>  (wlan0): device state change: 6 -> 4
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled.
..
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting..
.
Feb 26 09:30:45 dirac NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto eduroam' has se
curity, and secrets exist.  No new secrets needed.
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'password' value '<omitted>'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'eap' value 'PEAP'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'fragment_size' value '1300'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'phase1' value 'peapver=1'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'phase2' value 'auth=MSCHAPV2'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'identity' value 'lmedinas@ua.pt'
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-Networ
kManagerSettings-1-ca_cert'
Feb 26 09:30:45 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 26 09:30:45 dirac NetworkManager: <info>  Config: set interface ap_scan to 1
Feb 26 09:30:45 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanni
ng
Feb 26 09:30:45 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associated
Feb 26 09:30:47 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> associat
ing
Feb 26 09:30:49 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associa
ted
Feb 26 09:30:50 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> 4-way ha
ndshake
Feb 26 09:30:50 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  4-way handshake -> gro
up handshake
Feb 26 09:30:50 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  group handshake -> com
pleted
Feb 26 09:30:50 dirac NetworkManager: <info>  Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) s
uccessful.  Connected to wireless network 'eduroam'.
Feb 26 09:30:50 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) schedule
d.
Feb 26 09:30:50 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) started.
..
Feb 26 09:30:50 dirac NetworkManager: <info>  (wlan0): device state change: 5 -> 7
Feb 26 09:30:50 dirac NetworkManager: <info>  Activation (wlan0) Beginning DHCP transaction.
Feb 26 09:30:50 dirac NetworkManager: <info>  dhclient started with pid 4205
Feb 26 09:30:50 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete
.
Feb 26 09:30:50 dirac NetworkManager: <info>  DHCP: device wlan0 state changed normal exit -> preinit
Feb 26 09:30:55 dirac NetworkManager: <info>  DHCP: device wlan0 state changed preinit -> bound
Feb 26 09:30:55 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled.
..
Feb 26 09:30:55 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) started...
Feb 26 09:30:55 dirac NetworkManager: <info>    address 172.16.26.247
Feb 26 09:30:55 dirac NetworkManager: <info>    prefix 16 (255.255.0.0)
Feb 26 09:30:55 dirac NetworkManager: <info>    gateway 172.16.255.254
Feb 26 09:30:55 dirac NetworkManager: <info>    nameserver '193.136.172.20'
Feb 26 09:30:55 dirac NetworkManager: <info>    nameserver '193.136.172.21'
Feb 26 09:30:55 dirac NetworkManager: <info>    domain name 'wireless.ua.pt'
Feb 26 09:30:55 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) schedul
ed...
Feb 26 09:30:55 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete.
Feb 26 09:30:55 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started
...
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.107645] run_netconfig(): Spawning '/sbin/netconfi
g modify --service NetworkManager'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.124109] write_to_netconfig(): Writing to netconfi
g: INTERFACE='wlan0'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.124213] write_to_netconfig(): Writing to netconfi
g: DNSSEARCH='wireless.ua.pt wireless.ua.pt'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.124249] write_to_netconfig(): Writing to netconfi
g: DNSSERVERS='193.136.172.20 193.136.172.21'
Feb 26 09:30:56 dirac NetworkManager: <info>  Clearing nscd hosts cache.
Feb 26 09:30:56 dirac NetworkManager: <info>  (wlan0): device state change: 7 -> 8
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.129193] periodic_update(): Roamed from BSSID 00:0
F:24:D6:95:00 (eduroam) to 00:0F:24:D6:C1:00 (eduroam)
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.133837] run_netconfig(): Spawning '/sbin/netconfi
g modify --service NetworkManager'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.154439] write_to_netconfig(): Writing to netconfi
g: INTERFACE='wlan0'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.154743] write_to_netconfig(): Writing to netconfi
g: DNSSEARCH='wireless.ua.pt wireless.ua.pt'
Feb 26 09:30:56 dirac NetworkManager: <debug> [1235640656.154786] write_to_netconfig(): Writing to netconfi
g: DNSSERVERS='193.136.172.20 193.136.172.21'
Feb 26 09:30:56 dirac NetworkManager: <info>  Clearing nscd hosts cache.
Feb 26 09:30:56 dirac NetworkManager: <info>  Policy set 'Auto eduroam' (wlan0) as default for routing and 
DNS.
Feb 26 09:30:56 dirac NetworkManager: <info>  Activation (wlan0) successful, device activated.
Feb 26 09:30:56 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complet
e.
Feb 26 09:31:50 dirac NetworkManager: <debug> [1235640710.229367] periodic_update(): Roamed from BSSID 00:0
F:24:D6:C1:00 (eduroam) to (none) ((none))
Feb 26 09:31:50 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> associati
ng
Feb 26 09:31:52 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associa
ted
Feb 26 09:31:55 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> 4-way ha
ndshake
Feb 26 09:31:55 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  4-way handshake -> gro
up handshake
Feb 26 09:31:56 dirac NetworkManager: <debug> [1235640716.233297] periodic_update(): Roamed from BSSID (non
e) ((none)) to 00:0F:24:D6:A7:20 (eduroam)
Feb 26 09:31:56 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  group handshake -> com
pleted
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  completed -> disconnec
ted
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): supplicant manager state:  idle -> down
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): device state change: 8 -> 2
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): deactivating device (reason: 10).
Feb 26 09:32:31 dirac NetworkManager: <info>  wlan0: canceled DHCP transaction, dhcp client pid 4205
Feb 26 09:32:31 dirac NetworkManager: <debug> [1235640751.464343] run_netconfig(): Spawning '/sbin/netconfi
g modify --service NetworkManager'
Feb 26 09:32:31 dirac NetworkManager: <debug> [1235640751.466438] write_to_netconfig(): Writing to netconfi
g: INTERFACE='wlan0'
Feb 26 09:32:31 dirac NetworkManager: <info>  Clearing nscd hosts cache.
Feb 26 09:32:31 dirac NetworkManager: supplicant_interface_acquire: assertion `mgr_state == NM_SUPPLICANT_M
ANAGER_STATE_IDLE' failed
Feb 26 09:32:31 dirac NetworkManager: <info>  Trying to start the supplicant...
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): supplicant manager state:  down -> idle
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): device state change: 2 -> 3
Feb 26 09:32:32 dirac NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) starting connection 'Auto eduroam'
Feb 26 09:32:32 dirac NetworkManager: <info>  (wlan0): device state change: 3 -> 4
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled.
..
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting..
.
Feb 26 09:32:32 dirac NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto eduroam' has se
curity, and secrets exist.  No new secrets needed.
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'password' value '<omitted>'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'eap' value 'PEAP'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'fragment_size' value '1300'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'phase1' value 'peapver=1'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'phase2' value 'auth=MSCHAPV2'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'identity' value 'lmedinas@ua.pt'
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-Networ
kManagerSettings-1-ca_cert'
Feb 26 09:32:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 26 09:32:32 dirac NetworkManager: <info>  Config: set interface ap_scan to 1
Feb 26 09:32:32 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> disconnect
ed
Feb 26 09:32:32 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanni
ng
Feb 26 09:32:39 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> associat
ing
Feb 26 09:32:40 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associa
ted
Feb 26 09:32:47 dirac NetworkManager: <info>  wlan0: link timed out.
Feb 26 09:32:54 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> associat
ing
Feb 26 09:32:57 dirac NetworkManager: <info>  Activation (wlan0/wireless): association took too long.
Feb 26 09:32:57 dirac NetworkManager: <info>  (wlan0): device state change: 5 -> 6
Feb 26 09:32:57 dirac NetworkManager: <info>  Activation (wlan0/wireless): asking for new secrets
Feb 26 09:32:57 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> disconn
ected
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Feb 26 09:33:02 dirac NetworkManager: <info>  (wlan0): device state change: 6 -> 4
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled.
..
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting..
.
Feb 26 09:33:02 dirac NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0/wireless): connection 'Auto eduroam' has se
curity, and secrets exist.  No new secrets needed.
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'ssid' value 'eduroam'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'password' value '<omitted>'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'eap' value 'PEAP'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'fragment_size' value '1300'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'phase1' value 'peapver=0'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'phase2' value 'auth=MSCHAPV2'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'identity' value 'lmedinas@ua.pt'
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: added 'ca_cert' value 'blob://-org-freedesktop-Networ
kManagerSettings-1-ca_cert'
Feb 26 09:33:02 dirac NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Feb 26 09:33:02 dirac NetworkManager: <info>  Config: set interface ap_scan to 1
Feb 26 09:33:02 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanni
ng
Feb 26 09:33:04 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associatin
g
Feb 26 09:33:17 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> disconn
ected
Feb 26 09:33:17 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanni
ng
Feb 26 09:33:19 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associatin
g
Feb 26 09:33:21 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associa
ted
Feb 26 09:33:24 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> associat
ing
Feb 26 09:33:27 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associa
ted
Feb 26 09:33:27 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> 4-way ha
ndshake
Feb 26 09:33:27 dirac NetworkManager: <info>  (wlan0): supplicant connection state:  group handshake -> com
pleted
Feb 26 09:33:27 dirac NetworkManager: <info>  Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) s
uccessful.  Connected to wireless network 'eduroam'.
Feb 26 09:33:27 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) schedule
d.
Feb 26 09:33:27 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) started.
..
Feb 26 09:33:27 dirac NetworkManager: <info>  (wlan0): device state change: 5 -> 7
Feb 26 09:33:27 dirac NetworkManager: <info>  Activation (wlan0) Beginning DHCP transaction.
Feb 26 09:33:27 dirac NetworkManager: <info>  dhclient started with pid 4951
Feb 26 09:33:27 dirac NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete
.
Feb 26 09:33:27 dirac NetworkManager: <info>  DHCP: device wlan0 state changed normal exit -> preinit
Feb 26 09:33:32 dirac NetworkManager: <info>  DHCP: device wlan0 state changed preinit -> bound
Feb 26 09:33:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled.
..
Feb 26 09:33:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) started...
Feb 26 09:33:32 dirac NetworkManager: <info>    address 172.16.26.247
Feb 26 09:33:32 dirac NetworkManager: <info>    prefix 16 (255.255.0.0)
Feb 26 09:33:32 dirac NetworkManager: <info>    gateway 172.16.255.254
Feb 26 09:33:32 dirac NetworkManager: <info>    nameserver '193.136.172.20'
Feb 26 09:33:32 dirac NetworkManager: <info>    nameserver '193.136.172.21'
Feb 26 09:33:32 dirac NetworkManager: <info>    domain name 'wireless.ua.pt'
Feb 26 09:33:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) schedul
ed...
Feb 26 09:33:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete.
Feb 26 09:33:32 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started
...
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.195039] run_netconfig(): Spawning '/sbin/netconfi
g modify --service NetworkManager'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.197584] write_to_netconfig(): Writing to netconfi
g: INTERFACE='wlan0'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.197663] write_to_netconfig(): Writing to netconfi
g: DNSSEARCH='wireless.ua.pt wireless.ua.pt'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.197697] write_to_netconfig(): Writing to netconfi
g: DNSSERVERS='193.136.172.20 193.136.172.21'
Feb 26 09:33:33 dirac NetworkManager: <info>  Clearing nscd hosts cache.
Feb 26 09:33:33 dirac NetworkManager: <info>  (wlan0): device state change: 7 -> 8
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.202123] periodic_update(): Roamed from BSSID 00:0
F:24:D6:C5:60 (eduroam) to 00:0F:24:D6:C1:00 (eduroam)
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.205971] run_netconfig(): Spawning '/sbin/netconfi
g modify --service NetworkManager'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.208105] write_to_netconfig(): Writing to netconfi
g: INTERFACE='wlan0'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.208323] write_to_netconfig(): Writing to netconfi
g: DNSSEARCH='wireless.ua.pt wireless.ua.pt'
Feb 26 09:33:33 dirac NetworkManager: <debug> [1235640813.208484] write_to_netconfig(): Writing to netconfi
g: DNSSERVERS='193.136.172.20 193.136.172.21'
Feb 26 09:33:33 dirac NetworkManager: <info>  Clearing nscd hosts cache.
Feb 26 09:33:33 dirac NetworkManager: <info>  Policy set 'Auto eduroam' (wlan0) as default for routing and 
DNS.
Feb 26 09:33:33 dirac NetworkManager: <info>  Activation (wlan0) successful, device activated.
Feb 26 09:33:33 dirac NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complet
e.
Comment 13 Luis Medinas 2009-02-26 09:43:26 UTC
Created attachment 129553 [details]
NM sucesseful connection log

Sorry for the delay here's the debug log after a few attempts to connect.
Comment 14 Luis Medinas 2009-02-26 09:44:42 UTC
Sorry for the duplicate log, bugs.g.o is slow.
Comment 15 Dan Williams 2009-03-04 18:32:34 UTC
Looks like the supplicant is getting killed somewhere underneath NetworkManager.  That could either be a supplicant crash, or something killing the supplicant explicitly:

Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): supplicant connection
state:  completed -> disconnected
Feb 26 09:32:31 dirac NetworkManager: <info>  (wlan0): supplicant manager
state:  idle -> down

Any idea what could be doing that?  In any case, you could try to (as root):

1) stop NetworkManager with whatever SUSE uses to stop a service
2) killall -TERM wpa_supplicant
3) /usr/sbin/wpa_supplicant -dddt -u
4) in a different terminal, start NetworkManager

wait until the disconnection happens, then grab the output from the wpa_supplicant process in step 3 and attach it to this bug.  That will tell us whether it has segfaulted, or been told to quit by something else.
Comment 16 Luis Medinas 2009-03-23 14:39:39 UTC
Heres the log before disconnect:


1237818765.165079:   key_iv - hexdump(len=16): bb 93 41 15 a0 3a d4 72 e4 ea a0 63 1b 4e ce 30
1237818765.165085:   key_rsc - hexdump(len=8): 83 0c 00 00 00 00 00 00
1237818765.165090:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1237818765.165095:   key_mic - hexdump(len=16): 63 d8 af bb ff 61 02 78 26 23 b8 8f b1 48 ce f8
1237818765.165103: WPA: RX EAPOL-Key - hexdump(len=131): 01 03 00 7f fe 03 91 00 20 00 00 00 00 00 00 00 03 0b 89 a9 4d c5 d5 33 a6 46 f8 25 36 09 fc 3e 6b 0d 17 70 85 12 7f e4 46 58 15 79 1d 60 72 ab ee bb 93 41 15 a0 3a d4 72 e4 ea a0 63 1b 4e ce 30 83 0c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 63 d8 af bb ff 61 02 78 26 23 b8 8f b1 48 ce f8 00 20 5c dd 68 1b c5 dc ca e1 5a 14 38 7d 8b b5 74 d6 9c b2 73 d9 85 04 92 06 87 3b a2 c0 e1 c1 52 b7
1237818765.165135: WPA: RX message 1 of Group Key Handshake from 00:0f:24:d6:9e:f0 (ver=1)
1237818765.165143: State: GROUP_HANDSHAKE -> GROUP_HANDSHAKE
1237818765.165148: WPA: Group Key - hexdump(len=32): [REMOVED]
1237818765.175856: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32).
1237818765.175868: WPA: RSC - hexdump(len=6): 83 0c 00 00 00 00
1237818765.175875: wpa_driver_wext_set_key: alg=2 key_idx=1 set_tx=0 seq_len=6 key_len=32
1237818765.175895: WPA: Sending EAPOL-Key 2/2
1237818765.175904: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f fe 03 11 00 20 00 00 00 00 00 00 00 03 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 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 ea 6a 43 4d ff c3 eb ec 43 fa 32 59 7f fe 68 6d 00 00
1237818765.175971: WPA: Key negotiation completed with 00:0f:24:d6:9e:f0 [PTK=TKIP GTK=TKIP]
1237818765.176020: Cancelling authentication timeout
1237818765.176026: State: GROUP_HANDSHAKE -> COMPLETED
1237818765.176085: CTRL-EVENT-CONNECTED - Connection to 00:0f:24:d6:9e:f0 completed (reauth) [id=0 id_str=]
1237818765.176093: wpa_driver_wext_set_operstate: operstate 0->1 (UP)
1237818765.176098: WEXT: Operstate: linkmode=-1, operstate=6
1237818765.176440: EAPOL: External notification - portValid=1
1237818765.176450: EAPOL: SUPP_PAE entering state AUTHENTICATED
1237818765.176456: EAPOL authentication completed successfully
1237818765.176472: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1237818765.176479: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818768.050358: EAPOL: startWhen --> 0
1237818795.125362: EAPOL: authWhile --> 0
1237818825.201362: EAPOL: idleWhile --> 0
1237818825.201390: EAPOL: disable timer tick
1237818871.084569: RX EAPOL from 00:0f:24:d6:9e:f0
1237818871.084598: RX EAPOL - hexdump(len=131): 01 03 00 7f fe 03 a1 00 20 00 00 00 00 00 00 00 04 0b 89 a9 4d c5 d5 33 a6 46 f8 25 36 09 fc 3e 6b 0d 17 70 85 12 7f e4 46 58 15 79 1d 60 72 ab f0 38 f1 b7 a5 a6 a3 02 c7 83 05 3d 51 cd 08 c3 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 77 0f 40 6c f2 2c 25 38 70 d2 69 b9 30 38 e8 4c 00 20 04 86 75 5b 7f 50 b0 90 a7 09 4f b9 4e e2 43 37 2d 5d c6 41 4c 28 c7 f8 a7 29 b6 9e c7 89 2f f0
1237818871.084654: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
1237818871.084666: IEEE 802.1X RX: version=1 type=3 length=127
1237818871.084675:   EAPOL-Key type=254
1237818871.084683:   key_info 0x3a1 (ver=1 keyidx=2 rsvd=0 Group Ack MIC Secure)
1237818871.084695:   key_length=32 key_data_length=32
1237818871.084703:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04
1237818871.084714:   key_nonce - hexdump(len=32): 0b 89 a9 4d c5 d5 33 a6 46 f8 25 36 09 fc 3e 6b 0d 17 70 85 12 7f e4 46 58 15 79 1d 60 72 ab f0
1237818871.084733:   key_iv - hexdump(len=16): 38 f1 b7 a5 a6 a3 02 c7 83 05 3d 51 cd 08 c3 03
1237818871.084747:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1237818871.084758:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1237818871.084769:   key_mic - hexdump(len=16): 77 0f 40 6c f2 2c 25 38 70 d2 69 b9 30 38 e8 4c
1237818871.084785: WPA: RX EAPOL-Key - hexdump(len=131): 01 03 00 7f fe 03 a1 00 20 00 00 00 00 00 00 00 04 0b 89 a9 4d c5 d5 33 a6 46 f8 25 36 09 fc 3e 6b 0d 17 70 85 12 7f e4 46 58 15 79 1d 60 72 ab f0 38 f1 b7 a5 a6 a3 02 c7 83 05 3d 51 cd 08 c3 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 77 0f 40 6c f2 2c 25 38 70 d2 69 b9 30 38 e8 4c 00 20 04 86 75 5b 7f 50 b0 90 a7 09 4f b9 4e e2 43 37 2d 5d c6 41 4c 28 c7 f8 a7 29 b6 9e c7 89 2f f0
1237818871.084848: WPA: RX message 1 of Group Key Handshake from 00:0f:24:d6:9e:f0 (ver=1)
1237818871.084867: State: COMPLETED -> GROUP_HANDSHAKE
1237818871.085635: WPA: Group Key - hexdump(len=32): [REMOVED]
1237818871.085645: WPA: Installing GTK to the driver (keyidx=2 tx=0 len=32).
1237818871.085650: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
1237818871.085656: wpa_driver_wext_set_key: alg=2 key_idx=2 set_tx=0 seq_len=6 key_len=32
1237818871.085712: WPA: Sending EAPOL-Key 2/2
1237818871.085721: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f fe 03 21 00 20 00 00 00 00 00 00 00 04 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 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 f5 5f 3e 74 fc 7b 54 4f 57 5e 89 98 4b a0 92 ad 00 00
1237818871.085780: WPA: Group rekeying completed with 00:0f:24:d6:9e:f0 [GTK=TKIP]
1237818871.085787: Cancelling authentication timeout
1237818871.085793: State: GROUP_HANDSHAKE -> COMPLETED
1237818880.525873: Setting scan request: 0 sec 0 usec
1237818880.525949: Starting AP scan (broadcast SSID)
1237818880.525979: Scan requested (ret=0) - scan timeout 30 seconds
1237818882.685829: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1237818882.685867: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818882.685879: Wireless event: cmd=0x8b19 len=16
1237818882.685966: Received 2115 bytes of scan results (7 BSSes)
1237818882.685988: CTRL-EVENT-SCAN-RESULTS 
1237818882.686054: Selecting BSS from priority group 0
1237818882.686065: Try to find WPA-enabled AP
1237818882.686073: 0: 00:0f:24:d6:9e:f0 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818882.686089:    selected based on WPA IE
1237818882.686097:    selected WPA AP 00:0f:24:d6:9e:f0 ssid='eduroam'
1237818882.686107: Try to find non-WPA AP
1237818882.686114: Already associated with the selected AP.
1237818882.693487: RTM_NEWLINK: operstate=1 ifi_flags=0x1043 ([UP][RUNNING])
1237818882.693729: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818882.693740: Wireless event: cmd=0x8b15 len=24
1237818882.693750: Wireless event: new AP: 00:00:00:00:00:00
1237818882.693766: Setting scan request: 0 sec 100000 usec
1237818882.693779: Added BSSID 00:0f:24:d6:9e:f0 into blacklist
1237818882.693791: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
1237818882.693800: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1237818882.714015: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
1237818882.714058: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
1237818882.714072: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
1237818882.714085: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0

1237818882.714099: State: COMPLETED -> DISCONNECTED
1237818882.714204: wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
1237818882.714217: WEXT: Operstate: linkmode=-1, operstate=5
1237818882.714235: EAPOL: External notification - portEnabled=0
1237818882.714245: EAPOL: SUPP_PAE entering state DISCONNECTED
1237818882.714253: EAPOL: SUPP_BE entering state INITIALIZE
1237818882.714264: EAP: EAP entering state DISABLED
1237818882.714272: EAPOL: External notification - portValid=0
1237818882.714285: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818882.714297: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818882.797349: State: DISCONNECTED -> SCANNING
1237818882.797561: Starting AP scan (specific SSID)
1237818882.797575: Scan SSID - hexdump_ascii(len=7):
     65 64 75 72 6f 61 6d                              eduroam         
1237818882.797610: Scan requested (ret=0) - scan timeout 30 seconds
1237818883.697834: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818883.697864: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818883.697876: Wireless event: cmd=0x8c02 len=215
1237818883.697887: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=0007656475726f616d01071618243048606cdd160050f20101000050f20201000050f20201000050f201dd070050f202000100 RespIEs=01079618243048606cdd180050f2020101820003a4000027a4000042435e0062322f00)'
1237818883.697902: Association info event
1237818883.697910: req_ies - hexdump(len=51): 00 07 65 64 75 72 6f 61 6d 01 07 16 18 24 30 48 60 6c dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 dd 07 00 50 f2 02 00 01 00
1237818883.697937: resp_ies - hexdump(len=35): 01 07 96 18 24 30 48 60 6c dd 18 00 50 f2 02 01 01 82 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
1237818883.697959: WPA: set own WPA/RSN IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818883.697985: RX EAPOL from 00:0f:24:d6:9e:f0
1237818883.697995: RX EAPOL - hexdump(len=51): 01 00 00 2f 01 01 00 2f 01 00 6e 65 74 77 6f 72 6b 69 64 3d 65 64 75 72 6f 61 6d 2c 6e 61 73 69 64 3d 66 69 73 2d 61 70 30 32 2c 70 6f 72 74 69 64 3d 30
1237818883.698024: EAPOL: Received EAP-Packet frame
1237818883.767931: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818883.767968: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818883.767981: Wireless event: cmd=0x8b15 len=24
1237818883.767990: Wireless event: new AP: 00:0f:24:d6:9e:f0
1237818883.768003: State: SCANNING -> ASSOCIATED
1237818883.769250: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818883.769266: WEXT: Operstate: linkmode=-1, operstate=5
1237818883.769289: Associated to a new BSS: BSSID=00:0f:24:d6:9e:f0
1237818883.769297: No keys have been configured - skip key clearing
1237818883.769303: Associated with 00:0f:24:d6:9e:f0
1237818883.769308: WPA: Association event - clear replay counter
1237818883.769312: WPA: Clear old PTK
1237818883.769315: EAPOL: External notification - portEnabled=0
1237818883.769325: EAPOL: External notification - portValid=0
1237818883.769330: EAPOL: External notification - portEnabled=1
1237818883.769333: EAPOL: SUPP_PAE entering state CONNECTING
1237818883.769336: EAPOL: enable timer tick
1237818883.769341: EAPOL: SUPP_BE entering state IDLE
1237818883.769345: EAP: EAP entering state INITIALIZE
1237818883.769350: EAP: maintaining EAP method data for fast reauthentication
1237818883.769356: EAP: EAP entering state IDLE
1237818883.769362: Setting authentication timeout: 10 sec 0 usec
1237818883.769367: Cancelling scan request
1237818883.769375: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818883.769381: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818885.921732: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818885.921769: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818885.921782: Wireless event: cmd=0x8b19 len=16
1237818885.921868: Received 2416 bytes of scan results (8 BSSes)
1237818885.921891: CTRL-EVENT-SCAN-RESULTS 
1237818885.922524: Selecting BSS from priority group 0
1237818885.922539: Try to find WPA-enabled AP
1237818885.922548: 0: 00:0f:24:d1:5f:c0 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818885.922563:    selected based on WPA IE
1237818885.922571:    selected WPA AP 00:0f:24:d1:5f:c0 ssid='eduroam'
1237818885.922581: Try to find non-WPA AP
1237818885.922595: Trying to associate with 00:0f:24:d1:5f:c0 (SSID='eduroam' freq=2437 MHz)
1237818885.922605: Cancelling scan request
1237818885.922613: WPA: clearing own WPA/RSN IE
1237818885.922822: Automatic auth_alg selection: 0x1
1237818885.922846: WPA: using IEEE 802.11i/D3.0
1237818885.922855: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
1237818885.922866: WPA: set AP WPA IE - hexdump(len=26): dd 18 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 28 00
1237818885.922885: WPA: clearing AP RSN IE
1237818885.922894: WPA: using GTK TKIP
1237818885.922902: WPA: using PTK TKIP
1237818885.922911: WPA: using KEY_MGMT 802.1X
1237818885.922919: WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818885.922937: No keys have been configured - skip key clearing
1237818885.922945: wpa_driver_wext_set_drop_unencrypted
1237818885.922955: State: ASSOCIATED -> ASSOCIATING
1237818885.923713: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818885.923731: WEXT: Operstate: linkmode=-1, operstate=5
1237818885.923750: wpa_driver_wext_associate
1237818885.923772: wpa_driver_wext_set_psk
1237818885.933335: Setting authentication timeout: 10 sec 0 usec
1237818885.933357: EAPOL: External notification - portControl=Auto
1237818885.933378: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818885.933389: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818885.933399: Wireless event: cmd=0x8b06 len=12
1237818885.933410: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818885.933419: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818885.933428: Wireless event: cmd=0x8b04 len=16
1237818886.774350: EAPOL: startWhen --> 0
1237818886.774384: EAPOL: SUPP_PAE entering state CONNECTING
1237818886.774393: EAPOL: txStart
1237818886.774402: BSSID not set when trying to send an EAPOL frame
1237818886.774418: Using the source address of the last received EAPOL frame 00:0f:24:d6:9e:f0 as the EAPOL destination
1237818886.774430: TX EAPOL: dst=00:0f:24:d6:9e:f0
1237818886.774439: TX EAPOL - hexdump(len=4): 01 01 00 00
1237818888.285560: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818888.285720: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818888.285788: Wireless event: cmd=0x8b19 len=16
1237818888.285934: Received 2416 bytes of scan results (8 BSSes)
1237818888.286209: CTRL-EVENT-SCAN-RESULTS 
1237818888.286661: Selecting BSS from priority group 0
1237818888.286676: Try to find WPA-enabled AP
1237818888.286685: 0: 00:0f:24:d6:9e:f0 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818888.286700:    selected based on WPA IE
1237818888.286707:    selected WPA AP 00:0f:24:d6:9e:f0 ssid='eduroam'
1237818888.286717: Try to find non-WPA AP
1237818888.286731: Trying to associate with 00:0f:24:d6:9e:f0 (SSID='eduroam' freq=2462 MHz)
1237818888.286742: Cancelling scan request
1237818888.286750: WPA: clearing own WPA/RSN IE
1237818888.287067: Automatic auth_alg selection: 0x1
1237818888.287093: WPA: using IEEE 802.11i/D3.0
1237818888.287102: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
1237818888.287113: WPA: set AP WPA IE - hexdump(len=26): dd 18 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 28 00
1237818888.287132: WPA: clearing AP RSN IE
1237818888.287140: WPA: using GTK TKIP
1237818888.287149: WPA: using PTK TKIP
1237818888.287157: WPA: using KEY_MGMT 802.1X
1237818888.287166: WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818888.287184: No keys have been configured - skip key clearing
1237818888.287192: wpa_driver_wext_set_drop_unencrypted
1237818888.287202: State: ASSOCIATING -> ASSOCIATING
1237818888.287211: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818888.287220: WEXT: Operstate: linkmode=-1, operstate=5
1237818888.287238: wpa_driver_wext_associate
1237818888.287258: wpa_driver_wext_set_psk
1237818888.297225: Setting authentication timeout: 10 sec 0 usec
1237818888.297245: EAPOL: External notification - portControl=Auto
1237818888.297859: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818888.297881: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818888.297891: Wireless event: cmd=0x8b06 len=12
1237818888.297904: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1237818888.297914: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818888.297923: Wireless event: cmd=0x8b04 len=16
1237818888.309667: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818888.309692: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818897.960160: No keys have been configured - skip key clearing
1237818897.960192: State: ASSOCIATING -> DISCONNECTED
1237818897.960257: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818897.960275: WEXT: Operstate: linkmode=-1, operstate=5
1237818897.960297: EAPOL: External notification - portEnabled=0
1237818897.960305: EAPOL: SUPP_PAE entering state DISCONNECTED
1237818897.960310: EAPOL: SUPP_BE entering state INITIALIZE
1237818897.960318: EAP: EAP entering state DISABLED
1237818897.960324: EAPOL: External notification - portValid=0
1237818897.960859: No keys have been configured - skip key clearing
1237818897.960877: State: DISCONNECTED -> DISCONNECTED
1237818897.960886: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818897.960896: WEXT: Operstate: linkmode=-1, operstate=5
1237818897.960911: EAPOL: External notification - portEnabled=0
1237818897.960923: EAPOL: External notification - portValid=0
1237818898.095393: ssid - hexdump_ascii(len=7):
     65 64 75 72 6f 61 6d                              eduroam         
1237818898.095420: fragment_size=1300 (0x514)
1237818898.095430: eap methods - hexdump(len=16): 00 00 00 00 19 00 00 00 00 00 00 00 00 00 00 00
1237818898.095441: key_mgmt: 0x1
1237818898.095450: password - hexdump_ascii(len=7):
     36 30 31 36 38 32 37                              xxxxxxxx         
1237818898.095463: phase1 - hexdump_ascii(len=9):
     70 65 61 70 76 65 72 3d 30                        peapver=0       
1237818898.095475: scan_ssid=1 (0x1)
1237818898.095483: phase2 - hexdump_ascii(len=13):
     61 75 74 68 3d 4d 53 43 48 41 50 56 32            auth=MSCHAPV2   
1237818898.095499: identity - hexdump_ascii(len=14):
     6c 6d 65 64 69 6e 61 73 40 75 61 2e 70 74         lmedinas@ua.pt  
1237818898.095529: ca_cert - hexdump_ascii(len=56):
     62 6c 6f 62 3a 2f 2f 2d 6f 72 67 2d 66 72 65 65   blob://-org-free
     64 65 73 6b 74 6f 70 2d 4e 65 74 77 6f 72 6b 4d   desktop-NetworkM
     61 6e 61 67 65 72 53 65 74 74 69 6e 67 73 2d 31   anagerSettings-1
     2d 63 61 5f 63 65 72 74                           -ca_cert        
1237818898.095887: Setting scan request: 0 sec 0 usec
1237818898.095917: State: DISCONNECTED -> SCANNING
1237818898.095948: Starting AP scan (broadcast SSID)
1237818898.095963: Scan requested (ret=0) - scan timeout 30 seconds
1237818898.298342: Authentication with 00:00:00:00:00:00 timed out.
1237818898.298437: BSSID 00:00:00:00:00:00 blacklist count incremented to 4
1237818898.298473: No keys have been configured - skip key clearing
1237818898.298505: State: SCANNING -> DISCONNECTED
1237818898.299153: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818898.299195: WEXT: Operstate: linkmode=-1, operstate=5
1237818898.299237: EAPOL: External notification - portEnabled=0
1237818898.299272: EAPOL: External notification - portValid=0
1237818898.299307: Setting scan request: 0 sec 0 usec
1237818898.299346: State: DISCONNECTED -> SCANNING
1237818898.299652: Starting AP scan (specific SSID)
1237818898.299689: Scan SSID - hexdump_ascii(len=7):
     65 64 75 72 6f 61 6d                              eduroam         
1237818898.299762: Scan requested (ret=0) - scan timeout 30 seconds
1237818900.577722: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818900.577763: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818900.577775: Wireless event: cmd=0x8b19 len=16
1237818900.577849: Received 1513 bytes of scan results (5 BSSes)
1237818900.577870: CTRL-EVENT-SCAN-RESULTS 
1237818900.577936: Selecting BSS from priority group 0
1237818900.577947: Try to find WPA-enabled AP
1237818900.577955: 0: 00:0f:24:d1:5f:c0 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818900.577969:    selected based on WPA IE
1237818900.577977:    selected WPA AP 00:0f:24:d1:5f:c0 ssid='eduroam'
1237818900.577987: Try to find non-WPA AP
1237818900.578000: Trying to associate with 00:0f:24:d1:5f:c0 (SSID='eduroam' freq=2437 MHz)
1237818900.578011: Cancelling scan request
1237818900.578019: WPA: clearing own WPA/RSN IE
1237818900.578622: Automatic auth_alg selection: 0x1
1237818900.578650: WPA: using IEEE 802.11i/D3.0
1237818900.578660: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
1237818900.578670: WPA: set AP WPA IE - hexdump(len=26): dd 18 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 28 00
1237818900.578690: WPA: clearing AP RSN IE
1237818900.578699: WPA: using GTK TKIP
1237818900.578707: WPA: using PTK TKIP
1237818900.578715: WPA: using KEY_MGMT 802.1X
1237818900.578724: WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818900.578742: No keys have been configured - skip key clearing
1237818900.578750: wpa_driver_wext_set_drop_unencrypted
1237818900.578760: State: SCANNING -> ASSOCIATING
1237818900.578835: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818900.578848: WEXT: Operstate: linkmode=-1, operstate=5
1237818900.578868: wpa_driver_wext_associate
1237818900.578889: wpa_driver_wext_set_psk
1237818900.589096: Setting authentication timeout: 10 sec 0 usec
1237818900.589588: EAPOL: External notification - portControl=Auto
1237818900.589624: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818900.589637: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818900.589645: Wireless event: cmd=0x8b06 len=12
1237818900.589654: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818900.589663: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818900.589669: Wireless event: cmd=0x8b04 len=16
1237818910.594355: Authentication with 00:0f:24:d1:5f:c0 timed out.
1237818910.594373: Added BSSID 00:0f:24:d1:5f:c0 into blacklist
1237818910.594381: No keys have been configured - skip key clearing
1237818910.594387: State: ASSOCIATING -> DISCONNECTED
1237818910.594449: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818910.594459: WEXT: Operstate: linkmode=-1, operstate=5
1237818910.594474: EAPOL: External notification - portEnabled=0
1237818910.594481: EAPOL: External notification - portValid=0
1237818910.594489: Setting scan request: 0 sec 0 usec
1237818910.594505: State: DISCONNECTED -> SCANNING
1237818910.594535: Starting AP scan (broadcast SSID)
1237818910.594554: Scan requested (ret=0) - scan timeout 30 seconds
1237818912.949887: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818912.949920: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818912.949933: Wireless event: cmd=0x8b19 len=16
1237818912.950002: Received 1212 bytes of scan results (4 BSSes)
1237818912.950022: CTRL-EVENT-SCAN-RESULTS 
1237818912.950089: Selecting BSS from priority group 0
1237818912.950100: Try to find WPA-enabled AP
1237818912.950108: 0: 00:1f:9e:c0:d4:60 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818912.950123:    selected based on WPA IE
1237818912.950131:    selected WPA AP 00:1f:9e:c0:d4:60 ssid='eduroam'
1237818912.950141: Try to find non-WPA AP
1237818912.950154: Trying to associate with 00:1f:9e:c0:d4:60 (SSID='eduroam' freq=2412 MHz)
1237818912.950165: Cancelling scan request
1237818912.950173: WPA: clearing own WPA/RSN IE
1237818912.950191: Automatic auth_alg selection: 0x1
1237818912.950206: WPA: using IEEE 802.11i/D3.0
1237818912.950214: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
1237818912.950225: WPA: set AP WPA IE - hexdump(len=26): dd 18 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 28 00
1237818912.950244: WPA: clearing AP RSN IE
1237818912.950253: WPA: using GTK TKIP
1237818912.950261: WPA: using PTK TKIP
1237818912.950269: WPA: using KEY_MGMT 802.1X
1237818912.950277: WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818912.950296: No keys have been configured - skip key clearing
1237818912.950304: wpa_driver_wext_set_drop_unencrypted
1237818912.950314: State: SCANNING -> ASSOCIATING
1237818912.950381: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818912.950394: WEXT: Operstate: linkmode=-1, operstate=5
1237818912.950414: wpa_driver_wext_associate
1237818912.950435: wpa_driver_wext_set_psk
1237818912.960361: Setting authentication timeout: 10 sec 0 usec
1237818912.960380: EAPOL: External notification - portControl=Auto
1237818912.960399: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818912.960410: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818912.960419: Wireless event: cmd=0x8b06 len=12
1237818912.960741: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818912.960756: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818912.960766: Wireless event: cmd=0x8b04 len=16
1237818915.009323: Signal quality low (0/100)
1237818915.295020: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818915.295048: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818915.295059: Wireless event: cmd=0x8b19 len=16
1237818915.295133: Received 1814 bytes of scan results (6 BSSes)
1237818915.295151: CTRL-EVENT-SCAN-RESULTS 
1237818915.295213: Selecting BSS from priority group 0
1237818915.295222: Try to find WPA-enabled AP
1237818915.295228: 0: 00:0f:24:d1:5f:c0 ssid='eduroam' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1237818915.295240:    selected based on WPA IE
1237818915.295246:    selected WPA AP 00:0f:24:d1:5f:c0 ssid='eduroam'
1237818915.295254: Try to find non-WPA AP
1237818915.295265: Trying to associate with 00:0f:24:d1:5f:c0 (SSID='eduroam' freq=2437 MHz)
1237818915.295274: Cancelling scan request
1237818915.295280: WPA: clearing own WPA/RSN IE
1237818915.295296: Automatic auth_alg selection: 0x1
1237818915.295309: WPA: using IEEE 802.11i/D3.0
1237818915.295316: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 1 proto 1
1237818915.295324: WPA: set AP WPA IE - hexdump(len=26): dd 18 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01 28 00
1237818915.295342: WPA: clearing AP RSN IE
1237818915.295348: WPA: using GTK TKIP
1237818915.295354: WPA: using PTK TKIP
1237818915.295361: WPA: using KEY_MGMT 802.1X
1237818915.295367: WPA: Set own WPA IE default - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 01
1237818915.295383: No keys have been configured - skip key clearing
1237818915.295389: wpa_driver_wext_set_drop_unencrypted
1237818915.295397: State: ASSOCIATING -> ASSOCIATING
1237818915.295404: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818915.295411: WEXT: Operstate: linkmode=-1, operstate=5
1237818915.295429: wpa_driver_wext_associate
1237818915.295447: wpa_driver_wext_set_psk
1237818915.306546: Setting authentication timeout: 10 sec 0 usec
1237818915.306569: EAPOL: External notification - portControl=Auto
1237818915.306590: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818915.306599: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818915.306607: Wireless event: cmd=0x8b06 len=12
1237818915.306616: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1237818915.306624: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1237818915.306630: Wireless event: cmd=0x8b04 len=16
1237818916.833451: EAPOL: startWhen --> 0
1237818922.986851: No keys have been configured - skip key clearing
1237818922.986879: State: ASSOCIATING -> DISCONNECTED
1237818922.987373: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818922.987391: WEXT: Operstate: linkmode=-1, operstate=5
1237818922.987415: EAPOL: External notification - portEnabled=0
1237818922.987428: EAPOL: External notification - portValid=0
1237818922.987852: No keys have been configured - skip key clearing
1237818922.987866: State: DISCONNECTED -> DISCONNECTED
1237818922.987877: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818922.987888: WEXT: Operstate: linkmode=-1, operstate=5
1237818922.987904: EAPOL: External notification - portEnabled=0
1237818922.987914: EAPOL: External notification - portValid=0
1237818925.309446: Authentication with 00:00:00:00:00:00 timed out.
1237818925.309483: BSSID 00:00:00:00:00:00 blacklist count incremented to 5
1237818925.309497: No keys have been configured - skip key clearing
1237818925.309505: State: DISCONNECTED -> DISCONNECTED
1237818925.309515: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1237818925.309525: WEXT: Operstate: linkmode=-1, operstate=5
1237818925.309556: EAPOL: External notification - portEnabled=0
1237818925.309568: EAPOL: External notification - portValid=0
1237818925.309581: Setting scan request: 0 sec 0 usec
1237818943.909348: EAPOL: idleWhile --> 0
1237818943.909378: EAPOL: disable timer tick
Comment 17 Luis Medinas 2009-05-28 14:53:23 UTC
ok Dan, Tambet Ingo helped me with this problem and i got it fixed using NM 0.7.0. So here's my wpa_supplicant.conf file

 ctrl_interface=/var/run/wpa_supplicant

eapol_version=1
ap_scan=1
fast_reauth=1

network={
	ssid="eduroam"
	scan_ssid=1
	key_mgmt=WPA-EAP
	pairwise=TKIP
	group=TKIP
	eap=PEAP
	phase2="auth=MSCHAPv2"
	identity="user@domain.pt"
	password="xxxx"
}
I had to add the following keys to gconf -> system -> networking -> 802-11-wireless-security: pairwise (string) tkip and group (string) tkip.

Please add this options on networkmanager.
I hope this helps
Luis
Comment 18 Dan Williams 2010-02-01 20:55:30 UTC
That's pretty odd since wpa_supplicant should already be dropping CCMP/RSN support since the AP doesn't advertise it in the scan results.  What wpa_supplicant version are you using?
Comment 19 Tobias Mueller 2010-03-24 18:05:13 UTC
Closing this bug report as no further information has been provided. Please feel free to reopen this bug if you can provide the information asked for.
Thanks!