Fails to connect twice to WPA Enterprise

Bug #227609 reported by Alexey Androsov
6
Affects Status Importance Assigned to Milestone
network-manager (Ubuntu)
Triaged
Medium
Unassigned

Bug Description

I have Wi-fi with wpa enterprise encryption at work.

I configure connection with knetworkmanager
Encryption: WPA Enterprise
EAP: TLS
Profile: <email address hidden>
WPA: 2
Client key, ca key, privkey, password

All works well, but i have to configure it every day! Knetworkmanager can't automatically connect to this network another day.

OS: Kubuntu 8.04.
Notebook: Fujitsu-siemens s7110
Device (info from knetworkmanager): Intel Corporation PRO/Wireless 3945ABG Network Connection (wlan0)

Here is /var/log/daemon.log

Normail connect (manual configure):
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Device wlan0 activation scheduled...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) started...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May 7 09:18:15 aandrosov-laptop NetworkManager: <info> Activation (wlan0/wireless): access point 'Developers' is encrypted, and a key exists. No new key needed.
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'INTERFACE_ADD wlan0^I^Iwext^I/var/run/wpa_supplicant0^I'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'AP_SCAN 1'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'ADD_NETWORK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was '0'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 446576656c6f70657273'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA2'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-EAP'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 eap TLS'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 identity "#########"'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 private_key "/home/###########/privkey.pem"'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 private_key_passwd <key>'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 client_cert "/home/#######/client.cer"'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ca_cert "/home/###########/cachain.pem"'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 fragment_size 1300'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:18:17 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 7 09:18:21 aandrosov-laptop NetworkManager: <info> Old device 'wlan0' activating, won't change.
May 7 09:18:21 aandrosov-laptop NetworkManager: <info> Supplicant state changed: 1
May 7 09:18:21 aandrosov-laptop NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to access point 'Developers'.
May 7 09:18:21 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
May 7 09:18:21 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
May 7 09:18:22 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Beginning DHCP transaction.

Automatic connection:
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Device wlan0 activation scheduled...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) started...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May 7 09:16:53 aandrosov-laptop NetworkManager: <info> Activation (wlan0/wireless): access point 'Developers' is encrypted, and a key exists. No new key needed.
May 7 09:16:54 aandrosov-laptop NetworkManager: <info> SUP: sending command 'INTERFACE_ADD wlan0^I^Iwext^I/var/run/wpa_supplicant0^I'
May 7 09:16:54 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'AP_SCAN 1'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'ADD_NETWORK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was '0'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 446576656c6f70657273'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA2'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-EAP'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 eap TLS'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 identity "############"'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 private_key "/home/#########/privkey.pem"'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 private_key_passwd <key>'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 client_cert "/home/######/client.cer"'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ca_cert "/home/#######/cachain.pem"'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise TKIP'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group TKIP'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 fragment_size 1300'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 7 09:16:58 aandrosov-laptop NetworkManager: <info> Old device 'wlan0' activating, won't change.
May 7 09:17:27 aandrosov-laptop last message repeated 3 times
May 7 09:17:42 aandrosov-laptop NetworkManager: <WARN> request_and_convert_scan_results(): card took too much time scanning. Get a better one.
May 7 09:17:51 aandrosov-laptop NetworkManager: <info> Old device 'wlan0' activating, won't change.
May 7 09:18:00 aandrosov-laptop NetworkManager: <WARN> request_and_convert_scan_results(): card took too much time scanning. Get a better one.
May 7 09:18:07 aandrosov-laptop NetworkManager: <info> Old device 'wlan0' activating, won't change.

As you can see knetworkmanager sent 2 additional headers when connect automatically:
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise TKIP'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: response was 'OK'
May 7 09:16:55 aandrosov-laptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group TKIP'

Revision history for this message
Ranjan (ranjansimon) wrote :

I confirm this. This is the same problem with my machine too. I got the same Intel Corporation PRO/Wireless 3945ABG wireless card. I have to configure my wireless setting everytime I restart my system. The error below keeps on repeating

May 8 19:49:59 sparta NetworkManager: <info> SUP: response was 'OK'
May 8 19:49:59 sparta NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'
May 8 19:49:59 sparta NetworkManager: <info> SUP: response was 'OK'
May 8 19:49:59 sparta NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May 8 19:50:05 sparta NetworkManager: <info> Old device 'wlan0' activating, won't change.
May 8 19:50:20 sparta NetworkManager: <info> Old device 'wlan0' activating, won't change.

I tried replacing network manager with WICD but it again needs reconfiguration of the network. tried with wep,WPA 1/2 .. all the same error.

Revision history for this message
Alexey Androsov (doochik) wrote :

Problem is solved when i change WPA Protocol from "Automatic" to "AES-CCMP"

I think, knetworknanager doesn't properly save wpa protocol (TKIP, AES-CCMP).

Some logs (/var/log/daemog.log):
I choose automatic wpa protocol (no wpa protocol headers):
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ca_cert "/home/###########/cachain.pem"'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 fragment_size 1300'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'

next time it send two additonal headers and i can't connect to network:
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ca_cert "/home/#######/cachain.pem"'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise TKIP'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group TKIP'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 fragment_size 1300'
NetworkManager: <info> SUP: response was 'OK'

When i choose AES-CCMP:
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ca_cert "ca_cert "/home/#######/cachain.pem"'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise CCMP'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group CCMP'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 fragment_size 1300'
NetworkManager: <info> SUP: response was 'OK'
NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0'

next time all works.

Revision history for this message
Jeff Rash (jeffrash) wrote :

Same issue here. It was working before I updated my kernel to 2.6.24-19-generic and now I'm seeing the same problem. Only I am using WPA2 Enterprise. Everything seems to work on the open network at home, but at work I need WPA2 to get on the network.

Revision history for this message
Alexander Sack (asac) wrote :

some drivers are slow. see bug 272185

Changed in network-manager:
importance: Undecided → Medium
status: New → Triaged
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.