Re: [Madwifi-devel] Re: madwifi(cvs), wpa_supp v0.2.5 and linksys router problem
Status: Beta
Brought to you by:
otaku
Menu
▾
▴
Re: [Madwifi-devel] Re: madwifi(cvs), wpa_supp v0.2.5 and linksys router problem
|
From: Sam L. <sa...@er...> - 2004-11-28 22:14:08
|
[hostap@ trimmed since it appears unrelated to hostap stuff] On Saturday 27 November 2004 05:24 pm, Jouni Malinen wrote: > On Fri, Nov 26, 2004 at 02:19:28PM +0100, Andreas Schuldei wrote: > > ok, here are some logs with debugging in the madwifi driver > > activated (by echo 1 > /proc/sys/dev/ath0/debug) > > Thanks. This is starting to point towards being something to do with the > driver and not wpa_supplicant, so I cc'ed madwifi-devel mailing list > which is probably a more suitable forum for this question. > > > Summary: > > WPA key handshake completes successfully, ar521x generates beacon miss > interrupt after about 90 seconds, scans fail for some reason during > following couple of minutes. > > In other words, it is the client driver that decides that the connection > is down. It is unclear to me why this is happening, though. One > explanation would be that the AP and client get out of sync with > beacons, but that should not really happen since the client is supposed > to do time sync based on the beacon frames in the first place.. > Alternatively, the AP could have indeed stopped sending beacons which > should be obvious if you can run a wireless sniffer to capture what > packets are being sent. > > If the AP is still up, but the client just misses couple of beacons, I > would prefer the driver to try a bit harder before reporting this as a > lost connection. I haven't looked into madwifi code to see how many > beacons need to be missed. Anyway, I would at least try to probe the AP > first (e.g., send ProbeReq for its BSSID) and only report disconnection > if no reply is received. The bmiss threshold is 7 and the bmiss handler tries to reassociate before resorting to scanning. > > > Details: > > Here's the driver debug for association: > > Nov 26 13:47:07 localhost kernel: NODS > 00:05:4e:4a:47:44->00:0f:66:45:e2:ad(00:0f:66:45:e2:ad) auth 1M > Nov 26 13:47:07 localhost kernel: b000 3a01 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 0000 0000 0100 0000 > Nov 26 13:47:07 localhost kernel: NODS > 00:05:4e:4a:47:44->00:0f:66:45:e2:ad(00:0f:66:45:e2:ad) assoc_req 1M > Nov 26 13:47:07 localhost kernel: 0000 3a01 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 1000 3104 6400 000c 4163 6365 7373 5f50 6f69 6e74 > 0108 8284 8b0c 1296 1824 3204 3048 606c dd16 0050 f201 0100 0050 f202 > 0100 0050 f204 0100 0050 f202 > Nov 26 13:47:07 localhost kernel: ath_tx_start: > link[3](edf9c86c)=2df9c898 (edf9c898) Info at the net80211 layer, not in the ath driver, is more useful. Separately, there's no indication of the configuration (e.g. hardware, os, or madwifi). The information printed by athstats is also typically useful; especially if it's run during the period of the event. > > This triggered association event to wpa_supplicant: > > Wireless event: cmd=0x8b1a len=25 > Wireless event: cmd=0x8b15 len=20 > Wireless event: new AP: 00:0f:66:45:e2:ad > Association event - clear replay counter > Associated to a new BSS: BSSID=00:0f:66:45:e2:ad > > Followed by RX of msg 1/4 > > WPA: RX message 1 of 4-Way Handshake from 00:0f:66:45:e2:ad (ver=2) > > and reply msg 2/4: > > WPA: Sending EAPOL-Key 2/4 > WPA: TX EAPOL-Key 2/4 - hexdump(len=137): 00 0f 66 45 e2 ad 00 05 4e 4a > 47 44 88 8e 01 03 00 77 fe 01 0a 00 10 00 00 00 00 00 00 00 00 12 7c 68 > 7c d0 e6 d0 c2 be e0 15 eb 30 f2 72 d6 7d f4 f9 42 aa 05 6d 23 82 66 cd > fa a0 9b 16 4b 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 17 9a 49 c1 f5 59 be 16 6f c9 a3 > d5 b8 53 2e 9c 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 > 04 01 00 00 50 f2 02 > > in the driver: > > Nov 26 13:47:07 localhost kernel: TODS > 00:05:4e:4a:47:44->00:0f:66:45:e2:ad(00:0f:66:45:e2:ad) data 36M > Nov 26 13:47:07 localhost kernel: 0801 2c00 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 2000 aaaa 0300 0000 888e 0103 0077 fe01 0a00 1000 > 0000 0000 0000 0012 7c68 7cd0 e6d0 c2be e015 eb30 f272 d67d f4f9 42aa > 056d 2382 66cd faa0 9b16 4b00 0000 0000 0000 0000 0000 0000 0000 0000 > 0000 0000 0000 0000 0000 0000 0000 0017 9a49 c1f5 59be 166f c9a3 d5b8 > 532e 9c00 18dd 1600 50f2 0101 0000 50f2 0201 0000 50f2 0401 0000 50f2 02 > > followed by msg 3/4 > > WPA: RX message 3 of 4-Way Handshake from 00:0f:66:45:e2:ad (ver=2) > > and reply, msg 4/4 > > WPA: Sending EAPOL-Key 4/4 > WPA: TX EAPOL-Key 4/4 - hexdump(len=113): 00 0f 66 45 e2 ad 00 05 4e 4a > 47 44 88 8e 01 03 00 5f fe 01 0a 00 10 00 00 00 00 00 00 00 01 12 7c 68 > 7c d0 e6 d0 c2 be e0 15 eb 30 f2 72 d6 7d f4 f9 42 aa 05 6d 23 82 66 cd > fa a0 9b 16 4b 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 e6 35 f0 27 f8 b2 9a c5 0b 17 a6 > cb df af d0 e8 00 00 > > Nov 26 13:47:07 localhost kernel: ath_tx_start: Q1: 00000000 37f8d830 > 013c009f 0000009b 22240000 000db92d > Nov 26 13:47:07 localhost kernel: TODS > 00:05:4e:4a:47:44->00:0f:66:45:e2:ad(00:0f:66:45:e2:ad) data 36M > Nov 26 13:47:07 localhost kernel: 0801 2c00 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 3000 aaaa 0300 0000 888e 0103 005f fe01 0a00 1000 > 0000 0000 0000 0112 7c68 7cd0 e6d0 c2be e015 eb30 f272 d67d f4f9 42aa > 056d 2382 66cd faa0 9b16 4b00 0000 0000 0000 0000 0000 0000 0000 0000 > 0000 0000 0000 0000 0000 0000 0000 00e6 35f0 27f8 b29a c50b 17a6 cbdf > afd0 e800 00 > > keys configured > > RX msg 1/2 (encrypted) > > Reply: > > WPA: Sending EAPOL-Key 2/2 > WPA: TX EAPOL-Key 2/2 - hexdump(len=113): 00 0f 66 45 e2 ad 00 05 4e 4a > 47 44 88 8e 01 03 00 5f fe 03 12 00 20 00 00 00 00 00 00 00 02 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 b5 87 22 4c 6b 01 a7 bf 71 5b 9e > e8 51 48 1e 43 00 00 > > Nov 26 13:47:07 localhost kernel: 0841 2c00 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 4000 0100 0020 0000 0000 aaaa 0300 0000 888e 0103 > 005f fe03 1200 2000 0000 0000 0000 0200 0000 0000 0000 0000 0000 0000 > 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 > 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 0000 00b5 8722 4c6b > 01a7 bf71 5b9e e851 481e 4300 00 > Nov 26 13:47:07 localhost kernel: ath_tx_start: Q1: 00000000 019e6e28 > 413c0097 0000008b 22240000 000db92d > Nov 26 13:47:07 localhost kernel: ath_tx_start: > link[1](edf9c8f0)=2df9c91c (edf9c91c) > > > At this point, connection is up and everything is done as far as > wpa_supplicant is concerned: > > WPA: Key negotiation completed with 00:0f:66:45:e2:ad > Cancelling authentication timeout > > Next things happening is driver reporting that the hardware reported > beacon miss: > > Nov 26 13:48:41 localhost kernel: ath_bmiss_tasklet > Nov 26 13:48:41 localhost kernel: NODS > 00:05:4e:4a:47:44->00:0f:66:45:e2:ad(00:0f:66:45:e2:ad) assoc_req 1M > Nov 26 13:48:41 localhost kernel: 0000 3a01 000f 6645 e2ad 0005 4e4a > 4744 000f 6645 e2ad 5000 1104 6400 000c 4163 6365 7373 5f50 6f69 6e74 > 0108 0204 0b0c 1216 1824 3204 3048 606c dd16 0050 f201 0100 0050 f202 > 0100 0050 f204 0100 0050 f202 > > I don't know what that assoc_req is; maybe the driver tries to associate > back with the AP in case of beacon miss The bmiss handler asks the net80211 layer to reassociate. > > This beacon miss is reported to wpa_supplicant as disconnect event: > > Wireless event: cmd=0x8b15 len=20 > Wireless event: new AP: 00:00:00:00:00:00 > Disconnect event - remove keys The state change in the 802.11 layer is what triggers the event. > > This triggers wpa_supplicant to start scanning. madwifi debug shows lots > of probe_req being sent, but all the scan results are empty (0 BSSes). > It seems to take minutes before getting real scan results. After this, > the same process seems to be repeated; this time with 128 seconds of > connection uptime before getting ath_bmiss_tasklet. Like I said, logs at the net80211 layer are likely more useful. OTOH bmiss probably indicates signal loss so it's not clear anything would make it up to the net80211 layer. The fact that nothing was received during the subsequent scan seems to confirm this. athstats would provide info in that area as would a sniffer log. Sam |