Re: Frequent Disconnects

[Bill Moseley <moseley hank org>]

Here's a trimmed down log of what seems to happen when the disconnect
occurs.  Not sure if it includes anything useful -- and I didn't
include lines after what seemed to be the reconnect start.

Tips on better debugging would be great.

-> 0 
RTM_NEWLINK: operstate=1 ifi_flags=0x1043 ([UP][RUNNING]) 
Wireless event: cmd=0x8b15 len=20 
Wireless event: new AP: 00:00:00:00:00:00 
Setting scan request: 0 sec 100000 usec 
Added BSSID 00:09:5b:b3:c7:18 into blacklist 
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys 
CTRL_IFACE monitor send - hexdump(len=41): 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 35 32 30 35 2d 31 33 00 
wpa_driver_madwifi_del_key: keyidx=0 
wpa_driver_madwifi_del_key: keyidx=1 
wpa_driver_madwifi_del_key: keyidx=2 
wpa_driver_madwifi_del_key: keyidx=3 
wpa_driver_madwifi_del_key: keyidx=0 
State: COMPLETED -> DISCONNECTED 
wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT) 
WEXT: Operstate: linkmode=-1, operstate=5 
EAPOL: External notification - portEnabled=0 
EAPOL: SUPP_PAE entering state DISCONNECTED 
EAPOL: SUPP_BE entering state INITIALIZE 
EAPOL: External notification - portValid=0 
EAPOL: External notification - EAP success=0 
^Iath0: link timed out. 
^ISWITCH: found better connection 'ath0/hanklan' than current connection 'ath0/hanklan'.  same_ssid=1, have_link=0 
^IWill activate connection 'ath0/hanklan'. 
^IDevice ath0 activation scheduled... 
^IDeactivating device ath0. 

Here's another disconnect without trimming.

Jul 16 23:39:10 tiger NetworkManager: <information>^IDHCP daemon state is now 3 (renew) for interface ath0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): ing state AUTHENTICATED 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: SUPP_BE entering state IDLE 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK, IFLA_IFNAME: Interface 'ath0' added 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: startWhen --> 0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Wireless event: cmd=0x8b19 len=8 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Received 805 bytes of scan results (4 BSSes) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Scan results: 4 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Selecting BSS from priority group 0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): 0: 00:09:5b:b3:c7:18 ssid='hanklan' wpa_ie_len=24 rsn_ie_len=0 caps=0x11 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654):    selected based on WPA IE 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Already associated with the selected AP. 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Wireless event: cmd=0x8b19 len=8 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Received 805 bytes of scan results (4 BSSes) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Scan results: 4 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Selecting BSS from priority group 0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): 0: 00:09:5b:b3:c7:18 ssid='hanklan' wpa_ie_len=24 rsn_ie_len=0 caps=0x11 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654):    selected based on WPA IE 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Already associated with the selected AP. 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK: operstate=1 ifi_flags=0x1043 ([UP][RUNNING]) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Wireless event: cmd=0x8b15 len=20 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Wireless event: new AP: 00:00:00:00:00:00 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654):  scan request: 0 sec 100000 usec 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Added BSSID 00:09:5b:b3:c7:18 into blacklist 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): CTRL_IFACE monitor send - hexdump(len=41): 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 35 32 30 35 2d 31 36 00 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_madwifi_del_key: keyidx=0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_madwifi_del_key: keyidx=1 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_madwifi_del_key: keyidx=2 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_madwifi_del_key: keyidx=3 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_madwifi_del_key: keyidx=0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): State: COMPLETED -> DISCONNECTED 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): WEXT: Operstate: linkmode=-1, operstate=5 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: External notification - portEnabled=0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: SUPP_PAE entering state DISCONNECTED 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: SUPP_BE entering state INITIALIZE 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: External notification - portValid=0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): EAPOL: External notification - EAP success=0 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP]) 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): RTM_NEWLINK, IFLA_IFNAME: Interface 'ath0' added 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): State: DISCONNECTED -> SCANNING 
Jul 16 23:42:17 tiger NetworkManager: <information>^Iwpa_supplicant(10654): Starting AP scan (broadcast SSID) 
Jul 16 23:42:25 tiger NetworkManager: <information>^Iath0: link timed out. 
Jul 16 23:42:25 tiger NetworkManager: <information>^ISWITCH: found better connection 'ath0/hanklan' than current connection 'ath0/hanklan'.  same_ssid=1, have_link=0 
Jul 16 23:42:25 tiger NetworkManager: <information>^IWill activate connection 'ath0/hanklan'. 
Jul 16 23:42:25 tiger NetworkManager: <information>^IDevice ath0 activation scheduled... 
Jul 16 23:42:25 tiger NetworkManager: <information>^IDeactivating device ath0. 


-- 
Bill Moseley
moseley hank org