Comment 43 for bug 352150

Revision history for this message
Sergio Machado (machadosergio) wrote :

I'm attaching syslog where you can see NetworkManager associating with the wifi router but failing to do the 4-way handshake:

Oct 7 00:06:44 machados-laptop kernel: [43718.678051] ipw2200: Firmware error detected. Restarting.
Oct 7 00:06:44 machados-laptop wpa_supplicant[869]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Oct 7 00:06:44 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: completed -> disconnected
Oct 7 00:06:44 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: disconnected -> scanning
Oct 7 00:06:45 machados-laptop wpa_supplicant[869]: Trying to associate with 00:05:ca:a6:09:18 (SSID='Maradona' freq=2412 MHz)
Oct 7 00:06:45 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: scanning -> associating
Oct 7 00:06:45 machados-laptop wpa_supplicant[869]: Associated with 00:05:ca:a6:09:18
Oct 7 00:06:45 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: associating -> associated
Oct 7 00:06:46 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: associated -> 4-way handshake
Oct 7 00:06:52 machados-laptop wpa_supplicant[869]: WPA: 4-Way Handshake failed - pre-shared key may be incorrect
Oct 7 00:06:52 machados-laptop wpa_supplicant[869]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Oct 7 00:06:52 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: 4-way handshake -> disconnected
Oct 7 00:06:52 machados-laptop wpa_supplicant[869]: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Oct 7 00:06:52 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: disconnected -> scanning
Oct 7 00:06:53 machados-laptop wpa_supplicant[869]: Trying to associate with 00:05:ca:a6:09:18 (SSID='Maradona' freq=2412 MHz)
Oct 7 00:06:53 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: scanning -> associating
Oct 7 00:06:54 machados-laptop wpa_supplicant[869]: Associated with 00:05:ca:a6:09:18

... This happens many times until I disable wireless and re-enable it .....

Oct 7 00:14:28 machados-laptop kernel: [44182.864792] ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: associated -> 4-way handshake
Oct 7 00:14:28 machados-laptop wpa_supplicant[869]: WPA: Key negotiation completed with 00:05:ca:a6:09:18 [PTK=CCMP GTK=TKIP]
Oct 7 00:14:28 machados-laptop wpa_supplicant[869]: CTRL-EVENT-CONNECTED - Connection to 00:05:ca:a6:09:18 completed (auth) [id=0 id_str=]
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: 4-way handshake -> group handshake
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> (eth1): supplicant connection state: group handshake -> completed
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> Activation (eth1/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'Maradona'.
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) started...
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> (eth1): device state change: 5 -> 7 (reason 0)
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> Activation (eth1) Beginning DHCPv4 transaction (timeout in 45 seconds)
Oct 7 00:14:28 machados-laptop NetworkManager[752]: <info> dhclient started with pid 17359
Oct 7 00:14:29 machados-laptop NetworkManager[752]: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.
Oct 7 00:14:29 machados-laptop dhclient: Internet Systems Consortium DHCP Client V3.1.3
Oct 7 00:14:29 machados-laptop dhclient: Copyright 2004-2009 Internet Systems Consortium.
Oct 7 00:14:29 machados-laptop dhclient: All rights reserved.
Oct 7 00:14:29 machados-laptop dhclient: For info, please visit https://www.isc.org/software/dhcp/
Oct 7 00:14:29 machados-laptop dhclient:
Oct 7 00:14:29 machados-laptop dhclient: Listening on LPF/eth1/00:16:6f:a8:ab:38
Oct 7 00:14:29 machados-laptop dhclient: Sending on LPF/eth1/00:16:6f:a8:ab:38
Oct 7 00:14:29 machados-laptop dhclient: Sending on Socket/fallback
Oct 7 00:14:29 machados-laptop dhclient: DHCPREQUEST of 192.168.1.7 on eth1 to 255.255.255.255 port 67
Oct 7 00:14:29 machados-laptop NetworkManager[752]: <info> (eth1): DHCPv4 state changed nbi -> preinit
Oct 7 00:14:29 machados-laptop dhclient: DHCPACK of 192.168.1.7 from 192.168.1.1