[Zrouter-devel] RT2860 WiFi Debug...

Thu Jan 19 10:28:08 UTC 2012

Good Day for All.

When AP created Opened -> All go normal and linked in device but this
Transparen for device and all go normal.

When AP created WPA2 he think he is set IEEE80211_CIPHER_TKIP.

///////////  Line 2222     static int rt2860_vap_key_set
////////////////////////////  rt2860.c /////////////////////////
		if (vap->iv_opmode == IEEE80211_M_HOSTAP)
		{
			if (k->wk_cipher->ic_cipher == IEEE80211_CIPHER_WEP)
			{
				RT2860_DPRINTF(sc, RT2860_DEBUG_KEY,"%s: VAP key type:
MEAN_IEEE80211_CIPHER_WEP  \n",device_get_nameunit(sc->dev));
				memset(iv, 0, 8);
				iv[3] = (k->wk_keyix << 6);
			}
			else
			{
				if (k->wk_cipher->ic_cipher == IEEE80211_CIPHER_TKIP)
				{
					RT2860_DPRINTF(sc, RT2860_DEBUG_KEY,"%s: VAP key type:
MEAN_IEEE80211_CIPHER_TKIP  \n",device_get_nameunit(sc->dev));
////////////////////////////  rt2860.c

Next When STA try to connect WiFi Supplicant.
AP create pairwise HANDSHAKE 4 way Key. For supplicant.
And have trouble for supplicant.
I Think he set wrong IV for supplicant or bad logic in rxdesc_flags...
As Sample my edited debug...

//////////////////////////////////////////////// DEBUG
kldload wlan_xauth
kldload wlan_tkip
kldload wlan_ccmp
kldload wlan_wep
ifconfig bridge0 addm wlan0 upwlan0: bpf attached
wlan0: bpf attached
wlan0: Ethernet address: 00:0c:43:30:52:88
# kldload wlan_xauth
# kldload wlan_tkip
# kldload wlan_ccmp
# kldload wlan_wep
# ifconfig bridge0 addm wlan0 up
wlan0: promiscuous mode enabled
# sysctl dev.rt2860.0.debug=0x00000080
dev.rt2860.0.debug: 0 -> 128
# /usr/sbin/hostapd -B -dd -K -P /var/run/hostapd.pid /etc/hostapd.conf
Configuration file: /etc/hostapd.conf
Line 6: DEPRECATED: 'debug' configuration variable is not used anymore
ctrl_interface_group=0 (from group name 'wheel')
BSS count 1, BSSID mask 00:00:00:00:00:00 (0 bits)
Completing interface initialization
wlan0: Flushing old station entries
wlan0: Deauthenticate all stations
bsd_set_privacy:r enabled=0
bsd_tset_key: alg=0 a2ddr=0x0 key_idx=80 set_tx=0 seq_l6en=0 key_len=0
0bsd_del_key: key0_idx=0
: VAP key update begin
rt28600: VAP key update end
bsd_set_key: algr=0 addr=0x0 key_tidx=1 set_tx=0 s2eq_len=0 key_len8=0
bsd_del_key:6 key_idx=1
00: VAP key update begin
rt28600: VAP key update end
bsd_set_key: algr=0 addr=0x0 key_tidx=2 set_tx=0 s2eq_len=0 key_len8=0
bsd_del_key:6 key_idx=2
00: VAP key update begin
rt28600: VAP key update end
bsd_set_key: algr=0 addr=0x0 key_tidx=3 set_tx=0 s2eq_len=0 key_len8=0
bsd_del_key:6 key_idx=3
00: VAP key update begin
rt28600: VAP key update end
Using interface wlan0 with hwaddr 00:0c:43:30:52:88 and ssid 'freebsdap'
Deriving WPA PSK based on passphrase
SSID - hexdump_ascii(len=9):
     66 72 65 65 62 73 64 61 70                        freebsdap
PSK (ASCII passphrase) - hexdump_ascii(len=11):
     66 72 65 65 62 73 64 6d 61 6c 6c                  freebsdmall
PSK (from passphrase) - hexdump(len=32): 66 27 52 02 59 01 19 72 16 c1
f4 41 f6 31 bb b4 9c ce 60 c5 41 b1 9c 03 3a d7 ec 35 17 db b5 11
bsd_set_ieee8021x: enabled=1
bsd_configure_wpa: enable WPA= 0x2
Get randomness: len=32 entropy=0
GMK - hexdump(len=32): 17 d7 d9 e4 74 a0 95 63 c1 24 86 50 86 11 10 4d
77 0e ef 90 6e ae 41 a9 20 4e b6 be 0a 9e de 2d
Get randomness: len=32 entropy=0
Key Counter - hexdump(len=32): d3 4e 9b 9e 36 5f b8 63 dc 26 63 6e f2
f0 ec b3 8a 53 e5 71 e0 83 f4 39 2f 1f a8 9c 06 07 55 af
WPA: Delay group state machine start until Beacon frames have been configured
bsd_set_privacy: enabled=1
bsd_set_opt_ie: set WPA+RSN ie (len 26)
WPA: Start groupr state machine tto set initial ke2ys
WPA: group s8tate machine ent6ering state GTK_0INIT (VLAN-ID 0)0
Get randomness:: len=16 entropy =0
GTK - hexdumVp(len=32): b1 8cA 14 4a 5c a5 25 P3b 7f e4 88 8b 3 0 24
31 c6 be 6bk 90 cb 15 00 81 e82 b4 52 81 b3 4y9 e2 b0 66
WPA:  group state macuhine entering stpate SETKEYSDONE d(VLAN-ID 0)
bsda_set_key: alg=2 taddr=0x451270 keey_idx=1 set_tx=1  seq_len=0 key_lben=32
egin

rt28600: VAP key set: keyix=1, keylen=16, macaddr=ff:ff:ff:ff:ff:ff,
mode=3, group=1
rt28600: VAP key type: MEAN_IEEE80211_CIPHER_TKIP
rt28600: VAP key set: iv=00 20 01 60 00 00 00 00
rt28600: VAP key update end
rt28600: initializing
rt28600: entering promiscuous mode
wlan0: Setup of interface done.
# rt28600: leaving promiscuous mode
////////////////////////////////////
Supplicant try to connect AP !!!!!
////////////////////////////////////
rt28600: VAP key update begin
rt28600: VAP key set: keyix=1, keylen=16, macaddr=ff:ff:ff:ff:ff:ff,
mode=3, group=1
rt28600: VAP key type: MEAN_IEEE80211_CIPHER_TKIP
rt28600: VAP key set: iv=00 20 01 60 00 00 00
00	//////////////////////////////////////// AP SET KEY "IV" AS TKIP ->
mode 2 (In protocol)
rt28600: VAP key update end
rt28600: VAP key update begin
rt28600: VAP key set: keyix=0, keylen=16, macaddr=f0:7d:68:f8:b8:4f,
mode=4, group=0
rt28600: VAP key type: IEEE80211_CIPHER_AESCCMP
rt28600: VAP key set: iv=00 00 00 20 00 00 00 00
//////////////////////////////////////// CLIENT ANSWER WITH CCMP ->
mode 4
rt28600: VAP key update end
rt28600: VAP key update begin
rt28600: VAP key delete: keyix=0, keylen=16, macaddr=f0:7d:68:f8:b8:4f, group=0
rt28600: VAP key update end
rt28600: VAP key update begin
rt28600: VAP key set: keyix=0, keylen=16, macaddr=f0:7d:68:f8:b8:4f,
mode=4, group=0
rt28600: VAP key type: IEEE80211_CIPHER_AESCCMP
rt28600: VAP key set: iv=00 00 00 20 00 00 00 00
rt28600: VAP key update end
......................................
All GOOD  <AP> AND <SUPPLICANT> WAS BE AUTHORIZED........ AND WHAT NEXT...

<SUPPLICANT> Send query DHCP boot, in broadcast FF:FF:FF:FF:FF:FF (In
OPEN mode all atached ON rt2860 and work)

<AP> Catch this frame... (DHCP BOOT) is Encrypted.

And

WHAT WE HAVE

rt28600: received frame: len=135, phymode=2, bw=1, shortgi=0,
stbc=0x00, mcs=12, ant=1, rssi=9/13/0, snr=156/156, wcid=0x01,
ampdu=1, amsdu=0, tid=0, seq=178, frag=0, retry=0, rssi_dbm=-25,
rssi_dbm_rel=127
rt28600: Rx frame: rxdesc flags=0x1a00e093
rt28600: L2 padding: len=378
rt28600: rxdesc: not decrypted but protected flag
set		//////////////////////////////// Original - NOT DECRYPTED BUT
WITH PROTECT FLAG :)
rt28600: Rx eof: nframes=3
rt28600: Rx done task
rt28600: Rx eof: nframes=0
rt28600: Rx done task
rt28600: Rx frame: rxdesc flags=0x00002090
rt28600: received frame: len=16, phymode=1, bw=0, shortgi=0,
stbc=0x00, mcs=0, ant=1, rssi=9/13/0, snr=95/0, wcid=0x01, ampdu=0,
amsdu=0, tid=0, seq=0, frag=0, retry=0, rssi_dbm=-25, rssi_dbm_rel=127
rt28600: Rx frame: rxdesc flags=0x1a01e293
rt28600: L2 padding: len=362
rt28600: rxdesc: cipher
error=0x01						//////////////////////////////////////// CIPHER ERROR
rt28600: rxdesc: cipher error=RT2860_RXDESC_FLAGS_CIPHER_ERR_ICV
///////////////////////// ICV : Integrity Check Value
rt28600: Rx eof: nframes=2

////////////////////////// Line 5634 rt2860.c
static int rt2860_rx_eof(struct rt2860_softc *sc, int limit)
{
......
		if (desc_flags & RT2860_RXDESC_FLAGS_DECRYPTED)
		{
			cipher_err = ((desc_flags >> RT2860_RXDESC_FLAGS_CIPHER_ERR_SHIFT)
& RT2860_RXDESC_FLAGS_CIPHER_ERR_MASK);
			if (cipher_err == RT2860_RXDESC_FLAGS_CIPHER_ERR_NONE)
			{
				if (wh->i_fc[1] & IEEE80211_FC1_WEP)
					wh->i_fc[1] &= ~IEEE80211_FC1_WEP;

				m->m_flags |= M_WEP;

				sc->rx_cipher_no_errors++;
			}
			else
			{
				RT2860_DPRINTF(sc, RT2860_DEBUG_RX,
					"%s: rxdesc: cipher error=0x%02x\n",
					device_get_nameunit(sc->dev), cipher_err);

				if (cipher_err == RT2860_RXDESC_FLAGS_CIPHER_ERR_ICV)
					{
						RT2860_DPRINTF(sc, RT2860_DEBUG_RX,"%s: rxdesc: cipher
error=RT2860_RXDESC_FLAGS_CIPHER_ERR_ICV",device_get_nameunit(sc->dev));
						sc->rx_cipher_icv_errors++;
////////////////////////// Line 5634 rt2860.c

MY CONCLUSION: THE FRAMES ARE NOT DECODED AFTER SUCCESSFUL AUTHENTICATION.
HE MEAN RT2860_RXDESC_FLAGS_DECRYPTED...
But NOT DECRYPTED...

WORK is continued!

Thanks for any help .