NM-0.6.4 + madwifi-0.9.2 at IETF: frequent 802.11a reconnects



I'm sitting at the IETF on their 802.11a network and I'm getting
pretty frequent 802.11 reconnects from network manager.  The log
looks like the following.  Why is this link timing out, and why
does it go through a full IP Address reset cycle?

-derek

Nov  8 21:27:48 cliodev NetworkManager: <information>   ath0: link timed out. 
Nov  8 21:27:48 cliodev NetworkManager: <information>   SWITCH: found better connection 'ath0/ietf67a' than current connection 'ath0/ietf67a'.  same_ssid=1, have_link=0 
Nov  8 21:27:48 cliodev NetworkManager: <information>   Will activate connection 'ath0/ietf67a'. 
Nov  8 21:27:48 cliodev NetworkManager: <information>   Device ath0 activation scheduled... 
Nov  8 21:27:48 cliodev NetworkManager: <information>   Deactivating device ath0. 
Nov  8 21:27:48 cliodev dhclient: wifi0: unknown hardware address type 801
Nov  8 21:27:48 cliodev dhclient: wifi0: unknown hardware address type 801
Nov  8 21:27:48 cliodev dhclient: DHCPRELEASE on ath0 to 130.129.2.11 port 67
Nov  8 21:27:48 cliodev named[1641]: D-BUS: dhclient for interface ath0 released lease - removing forwarders.
Nov  8 21:27:49 cliodev avahi-daemon[2138]: Interface ath0.IPv4 no longer relevant for mDNS.
Nov  8 21:27:49 cliodev avahi-daemon[2138]: Leaving mDNS multicast group on interface ath0.IPv4 with address 130.129.68.66.
Nov  8 21:27:49 cliodev avahi-daemon[2138]: Withdrawing address record for 130.129.68.66 on ath0.
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) started... 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 1 of 5 (Device Prepare) scheduled... 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 1 of 5 (Device Prepare) started... 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 2 of 5 (Device Configure) scheduled... 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 1 of 5 (Device Prepare) complete. 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 2 of 5 (Device Configure) starting... 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0/wireless): access point 'ietf67a' is unencrypted, no key needed. 
Nov  8 21:27:49 cliodev kernel: ADDRCONF(NETDEV_UP): ath0: link is not ready
Nov  8 21:27:49 cliodev NetworkManager: <information>   DHCP daemon state is now 14 (normal exit) for interface ath0 
Nov  8 21:27:49 cliodev NetworkManager: <information>   DHCP daemon state is now 11 (unknown) for interface ath0 
Nov  8 21:27:49 cliodev NetworkManager: <information>   DHCP daemon state is now 14 (normal exit) for interface ath0 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'INTERFACE_ADD ath0                madwifi /var/run/wpa_supplicant ' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was 'OK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'AP_SCAN 1' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was 'OK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'ADD_NETWORK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was '0' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'SET_NETWORK 0 ssid 69657466363761' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was 'OK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'SET_NETWORK 0 key_mgmt NONE' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was 'OK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: sending command 'ENABLE_NETWORK 0' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   SUP: response was 'OK' 
Nov  8 21:27:49 cliodev NetworkManager: <information>   Activation (ath0) Stage 2 of 5 (Device Configure) complete. 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): Global control interface '/var/run/wpa_supplicant-global' 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX global ctrl_iface - hexdump_ascii(len=52): 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817):      49 4e 54 45 52 46 41 43 45 5f 41 44 44 20 61 74   INTERFACE_ADD at 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817):      68 30 09 09 6d 61 64 77 69 66 69 09 2f 76 61 72   h0__madwifi_/var 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817):      2f 72 75 6e 2f 77 70 61 5f 73 75 70 70 6c 69 63   /run/wpa_supplic 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817):      61 6e 74 09                                       ant_             
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE GLOBAL INTERFACE_ADD 'ath0            madwifi /var/run/wpa_supplicant' 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): Initializing interface 'ath0' conf 'N/A' driver 'madwifi' ctrl_interface '/var/run/wpa_supplicant' 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): Initializing interface (2) 'ath0' 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAPOL: SUPP_PAE entering state DISCONNECTED 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAPOL: KEY_RX entering state NO_KEY_RECEIVE 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAPOL: SUPP_BE entering state INITIALIZE 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAP: EAP entering state DISABLED 
Nov  8 21:27:58 cliodev kernel: ADDRCONF(NETDEV_CHANGE): ath0: link becomes ready
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAPOL: External notification - portEnabled=0 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): EAPOL: External notification - portValid=0 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): SIOCGIWRANGE: WE(compiled)=20 WE(source)=13 enc_capa=0xf 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817):   capabilities: key_mgmt 0xf enc 0xf 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): Own MAC address: 00:05:4e:51:15:91 
Nov  8 21:27:58 cliodev NetworkManager: <information>   wpa_supplicant(17817): wpa_driver_madwifi_del_key: keyidx=0 
Nov  8 21:27:58 cliodev NetworkManager: <information>   Activation (ath0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to access point 'ietf67a'. 
Nov  8 21:27:58 cliodev NetworkManager: <information>   Activation (ath0) Stage 3 of 5 (IP Configure Start) scheduled. 
Nov  8 21:27:58 cliodev NetworkManager: <information>   Activation (ath0) Stage 3 of 5 (IP Configure Start) started... 
Nov  8 21:27:59 cliodev NetworkManager: <information>   Activation (ath0) Beginning DHCP transaction. 
Nov  8 21:27:59 cliodev dhclient: wifi0: unknown hardware address type 801
Nov  8 21:27:59 cliodev NetworkManager: <information>   Activation (ath0) Stage 3 of 5 (IP Configure Start) complete. 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): r_madwifi_del_key: keyidx=1 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): wpa_driver_madwifi_del_key: keyidx=2 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): wpa_driver_madwifi_del_key: keyidx=3 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): wpa_driver_madwifi_set_countermeasures: enabled=0 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): wpa_driver_madwifi_set_drop_unencrypted: enabled=1 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Setting scan request: 0 sec 100000 usec 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Added interface ath0 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Wireless event: cmd=0x8b06 len=8 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=9): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      41 50 5f 53 43 41 4e 20 31                        AP_SCAN 1        
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=11): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      41 44 44 5f 4e 45 54 57 4f 52 4b                  ADD_NETWORK      
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE: ADD_NETWORK 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=33): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      53 45 54 5f 4e 45 54 57 4f 52 4b 20 30 20 73 73   SET_NETWORK 0 ss 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      69 64 20 36 39 36 35 37 34 36 36 33 36 33 37 36   id 6965746636376 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      31                                                1                
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE: SET_NETWORK id=0 name='ssid' value='69657466363761' 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): ssid - hexdump_ascii(len=7): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      69 65 74 66 36 37 61                              ietf67a          
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=27): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):  54 57 4f 52 4b 20 30 20 6b 65   SET_NETWORK 0 ke 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      79 5f 6d 67 6d 74 20 4e 4f 4e 45                  y_mgmt NONE      
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE: SET_NETWORK id=0 name='key_mgmt' value='NONE' 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): key_mgmt: 0x4 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=16): 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      45 4e 41 42 4c 45 5f 4e 45 54 57 4f 52 4b 20 30   ENABLE_NETWORK 0 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE: ENABLE_NETWORK id=0 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Setting scan request: 0 sec 0 usec 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): State: DISCONNECTED -> SCANNING 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Starting AP scan (broadcast SSID) 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): RX ctrl_iface - hexdump_ascii(len=6): 
Nov  8 21:27:59 cliodev dhclient: wifi0: unknown hardware address type 801
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817):      41 54 54 41 43 48                                 ATTACH           
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): CTRL_IFACE monitor attached - hexdump(len=44): 2f 76 61 72 2f 72 75 6e 2f 4e 65 74 77 6f 72 6b 4d 61 6e 61 67 65 72 2f 77 70 61 5f 63 74 72 6c 5f 31 37 30 34 37 2d 34 35 00 00 00 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Wireless event: cmd=0x8b1a len=8 
Nov  8 21:27:59 cliodev NetworkManager: <information>   wpa_supplicant(17817): Wireless event: cmd=0x8b19 len=8 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): Received 4093 bytes of scan results (19 BSSes) 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): Scan results: 19 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): Selecting BSS from priority group 0 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 0: 00:15:c7:85:87:e0 ssid='ietf67a' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):  wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 2: 00:15:c7:81:8c:d0 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 3: 00:15:c7:85:8c:d0 ssid='ietf67a' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 4: 00:15:c7:85:78:30 ssid='ietf67a' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev dhclient: DHCPDISCOVER on ath0 to 255.255.255.255 port 67 interval 7
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 5: 00:15:c7:81:87:e0 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 6: 00:15:c7:81:78:30 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 7: 00:15:c7:81:69:50 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 8: 00:15:c7:81:78:f0 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 9: 00:15:c7:81:65:70 ssid='ietf67b' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 10: 00:15:c7:85:87:00 ssid='ietf67a' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817): 11: 00:15:c7:85:78:f0 ssid='ietf67a' wpa_ie_len=0 rsn_ie_len=0 caps=0x1 
Nov  8 21:28:00 cliodev NetworkManager: <information>   wpa_supplicant(17817):    skip - no WPA/RSN IE 
Nov  8 21:27:59 cliodev NetworkManager: <information>   DHCP daemon state is now 12 (successfully started) for interface ath0 
Nov  8 21:28:00 cliodev NetworkManager: <information>   DHCP daemon state is now 1 (starting) for interface ath0 
Nov  8 21:28:00 cliodev dhclient: DHCPOFFER from 130.129.64.3
Nov  8 21:28:00 cliodev dhclient: DHCPREQUEST on ath0 to 255.255.255.255 port 67
Nov  8 21:28:00 cliodev dhclient: DHCPACK from 130.129.64.3
Nov  8 21:28:00 cliodev NetworkManager: <information>   DHCP daemon state is now 2 (bound) for interface ath0 
Nov  8 21:28:00 cliodev NetworkManager: <information>   Activation (ath0) Stage 4 of 5 (IP Configure Get) scheduled... 
Nov  8 21:28:00 cliodev NetworkManager: <information>   Activation (ath0) Stage 4 of 5 (IP Configure Get) started... 
Nov  8 21:28:00 cliodev named[1641]: D-BUS: dhclient for interface ath0 acquired new lease - creating forwarders.
Nov  8 21:28:00 cliodev dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/ath0 for sub-path ath0.dbus.get.host_name
Nov  8 21:28:00 cliodev dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/ath0 for sub-path ath0.dbus.get.nis_domain
Nov  8 21:28:00 cliodev dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/ath0 for sub-path ath0.dbus.get.nis_servers
Nov  8 21:28:00 cliodev NetworkManager: <information>   Retrieved the following IP4 configuration from the DHCP daemon: 
Nov  8 21:28:00 cliodev NetworkManager: <information>     address 130.129.68.66 
Nov  8 21:28:00 cliodev NetworkManager: <information>     netmask 255.255.248.0 
Nov  8 21:28:00 cliodev NetworkManager: <information>     broadcast 130.129.71.255 
Nov  8 21:28:00 cliodev NetworkManager: <information>     gateway 130.129.64.1 
Nov  8 21:28:00 cliodev NetworkManager: <information>     nameserver 130.129.2.11 
Nov  8 21:28:00 cliodev NetworkManager: <information>     nameserver 130.129.2.13 
Nov  8 21:28:00 cliodev NetworkManager: <information>     domain name 'ietf67.org' 
Nov  8 21:28:00 cliodev NetworkManager: <information>   Activation (ath0) Stage 5 of 5 (IP Configure Commit) scheduled... 
Nov  8 21:28:00 cliodev NetworkManager: <information>   Activation (ath0) Stage 4 of 5 (IP Configure Get) complete. 
Nov  8 21:28:00 cliodev NetworkManager: <information>   Activation (ath0) Stage 5 of 5 (IP Configure Commit) started... 
Nov  8 21:28:00 cliodev avahi-daemon[2138]: New relevant interface ath0.IPv4 for mDNS.
Nov  8 21:28:00 cliodev avahi-daemon[2138]: Joining mDNS multicast group on interface ath0.IPv4 with address 130.129.68.66.
Nov  8 21:28:00 cliodev avahi-daemon[2138]: Registering new address record for 130.129.68.66 on ath0.
Nov  8 21:28:00 cliodev dhclient: bound to 130.129.68.66 -- renewal in 18641 seconds.
Nov  8 21:28:01 cliodev NetworkManager: <information>   Activation (ath0) successful, device activated. 
Nov  8 21:28:01 cliodev NetworkManager: <information>   Activation (ath0) Finish handler scheduled. 
Nov  8 21:28:01 cliodev NetworkManager: <information>   Activation (ath0) Stage 5 of 5 (IP Configure Commit) complete. 

-- 
       Derek Atkins, SB '93 MIT EE, SM '95 MIT Media Laboratory
       Member, MIT Student Information Processing Board  (SIPB)
       URL: http://web.mit.edu/warlord/    PP-ASEL-IA     N1NWH
       warlord MIT EDU                        PGP key available



[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]