Hi Irfan, On Fri, Nov 26, 2010 at 9:07 AM, Irfan Sheriff <[email protected]> wrote:
> I continue to see scan failures in the wpa_supplicant log, investigate > that. Look at how the interaction with the supplicant directly from the > wpa_cli works. > > What happens when you load the driver, start the supplicant and initiate > connection with a configured network from adb shell interface: > > # stop > # insmod driver > # setprop ctl.start wpa_supplicant > # wpa_cli reconnect > > Does it connect right away ? If not, the problem is not in the framework. > When I try to reconnect, I get the following error: # wpa_cli reconnect Using interface 'wlan0' Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory # cd /system/lib/modules # ls rt3070sta.ko # insmod rt3070stainit: service 'bootanim' is being killed init: waitpid returned pid 977, status = 0000000f init: process 'bootanim', pid 977 exited insmod: can't open 'rt3070sta' # insmod rt3070sta.ko rtusb init ---> ===>rt2870_probe()! --> RTMPAllocAdapterBlock === pAd = d0962000, size = 500648 === <-- RTMPAllocAdapterBlock, Status=0 NumEndpoints=7 BULK IN MaxPacketSize = 512 EP address = 0x81 BULK OUT MaxPacketSize = 512 EP address = 0x 1 BULK OUT MaxPacketSize = 512 EP address = 0x 2 BULK OUT MaxPacketSize = 512 EP address = 0x 3 BULK OUT MaxPacketSize = 512 EP address = 0x 4 BULK OUT MaxPacketSize = 512 EP address = 0x 5 BULK OUT MaxPacketSize = 512 EP address = 0x 6 STA Driver version-2.3.0.4 NVM is EEPROM Allocate a net device with private data size=0! Allocate net device ops success! The name of the new wlan interface is wlan0... RtmpOSNetDevAttach()---> <---RtmpOSNetDevAttach(), ret=0 <===rt2870_probe()! usbcore: registered new interface driver rt2870 # setprop ctl.start wpa_supplicant init: starting 'wpa_supplicant' # Allocate 8192 memory for BA reordering MAC_CSR0 [ Ver:Rev=0x30700201] <=== RtmpAsicLoadFirmware (status=0) --> RTMPAllocTxRxRingMemory --> NICInitTransmit MGMT Ring: total 32 entry allocated <-- NICInitTransmit(Status=0) --> NICInitRecv <-- NICInitRecv(Status=0) <-- RTMPAllocTxRxRingMemory, Status=0 --> MLME Initialize <-- MLME Initialize --> UserCfgInit --> UserCfgInit. BACapability = 0x3024040 <-- UserCfgInit --> NICInitializeAdapter <== DMA offset 0x208 = 0x0 --> NICInitializeAsic MAC_CSR0 [ Ver:Rev=0x30700201] -->RTUSBVenderReset <--RTUSBVenderReset BBP version = 60 --->Disable TSF synchronization <-- NICInitializeAsic <-- NICInitializeAdapter 1. Phy Mode = 0 2. Phy Mode = 0 --> NICReadEEPROMParameters --> E2PROM_CSR = 0x20408 --> EEPROMAddressNum = 6 Initialize MAC Address from E2PROM E2PROM MAC: =00:08:10:74:b5:da Use the MAC address what is assigned from EEPROM. Current MAC: =00:08:10:74:b5:da E2PROM: Version = 1, FAE release #1 NICReadEEPROMParameters: RxPath = 1, TxPath = 1 Chip specific bbpRegTbSize=0! E2PROM: G Tssi[-4 .. +4] = 255 255 255 255 - 255 -255 255 255 255, step=255, tuning=0 E2PROM: A Tssi[-4 .. +4] = 0 0 0 0 - 0 -0 0 0 0, step=0, tuning=0 E2PROM: RF FreqOffset=0x29 RTMPSetPhyMode : PhyMode=0, channel=0 country code=128/128, RFIC=5, PHY mode=0, support 11 channels RTMPSetPhyMode: channel is out of range, use first channel=1 Txpower per Rate Gpwrdelta = 0, Apwrdelta = 0 . 20MHz BW, 2.4G band-aaaa6666, Adata = aaaa6666, Gdata = aaaa6666 20MHz BW, 2.4G band-aaaa6688, Adata = aaaa6688, Gdata = aaaa6688 20MHz BW, 2.4G band-aaaa6688, Adata = aaaa6688, Gdata = aaaa6688 20MHz BW, 2.4G band-aaaa6688, Adata = aaaa6688, Gdata = aaaa6688 20MHz BW, 2.4G band-ffff6688, Adata = ffff6688, Gdata = ffff6688 <-- NICReadEEPROMParameters 3. Phy Mode = 0 --> NICInitAsicFromEEPROM AsicSetRxAnt, switch to main antenna RTMPFilterCalibration - CaliBW20RfR24=0xa, CaliBW40RfR24=0x28 RTMPSetLED::Mode=1,HighByte=0x20,LowByte=0x01 Use Hw Radio Control Pin=0; if used Pin=0; TxPath = 1, RxPath = 1, RFIC=5, Polar+LED mode=1 <-- NICInitAsicFromEEPROM RTMPSetPhyMode : PhyMode=0, channel=1 country code=128/128, RFIC=5, PHY mode=0, support 11 channels MCS Set = 00 00 00 00 00 NDIS_STATUS_MEDIA_DISCONNECT Event B! RTUSBBulkReceive! <==== rt28xx_init, Status=0 ==> RTMPEnableRxTx <== WRITE DMA offset 0x208 = 0x45 <== RTMPEnableRxTx 0x1300 = 00073200 STAMlmePeriodicExec():CNTL - ScanTab.BssNr==0, start a new ACTIVE scan SSID[] SCANNING, suspend MSDU transmission ... SYNC - BBP R4 to 20MHz.l ===> rt_ioctl_siwpmksa rt_ioctl_siwpmksa - IW_PMKSA_FLUSH ===>Set_NetworkType_Proc::(INFRA) Set_NetworkType_Proc::(NetworkType=1) ===>rt_ioctl_giwrange ==>rt_ioctl_giwmode(mode=0) rt_ioctl_siwauth::IW_AUTH_WPA_ENABLED - Driver supports WPA!(param->value = 1) AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=none WCIDAttri = 0x1 AsicRemovePairwiseKeyEntry : Wcid #1 AsicRemoveSharedKeyEntry: #0 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 rt_ioctl_siwencodeext::Remove all keys!(encoding->flags = 8401) AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=none WCIDAttri = 0x1 AsicRemovePairwiseKeyEntry : Wcid #1 AsicRemoveSharedKeyEntry: #1 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 rt_ioctl_siwencodeext::Remove all keys!(encoding->flags = 8402) AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=none WCIDAttri = 0x1 AsicRemovePairwiseKeyEntry : Wcid #1 AsicRemoveSharedKeyEntry: #2 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 rt_ioctl_siwencodeext::Remove all keys!(encoding->flags = 8403) AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=none WCIDAttri = 0x1 AsicRemovePairwiseKeyEntry : Wcid #1 AsicRemoveSharedKeyEntry: #3 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 rt_ioctl_siwencodeext::Remove all keys!(encoding->flags = 8404) rt_ioctl_siwauth::IW_AUTH_WPA_VERSION - param->value = 1! ===> rt_ioctl_siwpmksa rt_ioctl_siwpmksa - IW_PMKSA_FLUSH rt_ioctl_giwscan:: Still scanning !!! reset MLME state machine !!! MlmeRestartStateMachine !!! MLME busy, reset MLME state machine !!! SCAN done, resume MSDU transmission ... SCANNING, suspend MSDU transmission ... SYNC - BBP R4 to 20MHz.l SYNC - End of SCAN, restore to channel 1, Total BSS[01] SCAN done, resume MSDU transmission ... ===>rt_ioctl_giwscan. 1(1) BSS returned, data->length = 200 rt_ioctl_siwauth::IW_AUTH_80211_AUTH_ALG - param->value = 1! rt_ioctl_siwauth::IW_AUTH_WPA_VERSION - param->value = 1! ===>Set_NetworkType_Proc::(INFRA) Set_NetworkType_Proc::(NetworkType=1) ===> rt_ioctl_siwgenie rt_ioctl_siwauth::IW_AUTH_WPA_VERSION - param->value = 4! rt_ioctl_siwauth::IW_AUTH_CIPHER_PAIRWISE - param->value = 8! rt_ioctl_siwauth::IW_AUTH_CIPHER_GROUP - param->value = 4! rt_ioctl_siwauth::IW_AUTH_KEY_MGMT - param->value = 2! rt_ioctl_siwauth::IW_AUTH_PRIVACY_INVOKED - param->value = 1! ==>rt_ioctl_siwfreq::SIOCSIWFREQ[cmd=0x8b04] (Channel=1) Set_SSID_Proc::(Len=8,Ssid=Olympus2) CntlOidSsidProc():CNTL - 1 BSS of 1 BSS match the desire IOCTL::SIOCSIWAP 68:7f:74:1c:e4:7c (8)SSID - Olympus2 CNTL - iterate BSS 0 of 1 SYNC - MlmeJoinReqAction(BSS #0) SYNC - BBP R4 to 20MHz.l SYNC - Switch to ch 6, Wait BEACON from 68:7f:74:1c:e4:7c SYNC - receive desired BEACON at JoinWaitBeacon... Channel = 6 MlmeAux.ExtCapInfo=0 RTMPUpdateMlmeRate ==> MlmeTransmit = 0x0 SYNC - after JOIN, SupRateLen=8, ExtRateLen=4 !!! 20MHz !!! AUTH - Send AUTH request seq#1 (Alg=0)... AUTH - Receive AUTH_RSP seq#2 to me (Alg=0, Status=0) CNTL - AUTH OK ASSOC - Send ASSOC request... PeerAssocRspAction():ASSOC - receive ASSOC_RSP to me (status=0) PeerAssocRspAction():MacTable [255].AMsduSize = 0. ClientStatusFlags = 0x0 AssocPostProc===> AP.AMsduSize = 0. ClientStatusFlags = 0x0 AssocPostProc===> (Mmps=0, AmsduSize=0, ) AssocPostProc===> Store RSN_IE for WPA2 SM negotiation RSN_IE: d09c4674, len = 26 0x0000 : 30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f 0x0010 : ac 02 01 00 00 0f ac 02 0c 00 !!!Infra LINK UP !!! !!! LINK UP !!! (BssType=1, AID=4, ssid=Olympus2, Channel=6, CentralChannel = 4) !!! LINK UP !!! (Density =0, ) ==============> AsicSetBssid 68:7f:74:1c:e4:7c AsicSetEdcaParm NDIS_STATUS_MEDIA_DISCONNECT Event AA! RTMPWPARemoveAllKeys(AuthMode=7, WepStatus=6) AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=none WCIDAttri = 0x1 AsicRemovePairwiseKeyEntry : Wcid #1 remove none key #0 AsicRemoveSharedKeyEntry: #0 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 remove none key #1 AsicRemoveSharedKeyEntry: #1 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 remove none key #2 AsicRemoveSharedKeyEntry: #2 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 remove none key #3 AsicRemoveSharedKeyEntry: #3 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x0 ComposePsPoll --->AsicEnableBssSync(INFRA mode) !!! LINK UP !!! ClientStatusFlags=0) MlmeUpdateTxRates[MaxSupport = 54] = MaxDesire 54 Mbps MlmeUpdateTxRates (MaxDesire=54, MaxSupport=54, MaxTxRate=54, MinRate=1, Rate Switching =1) MlmeUpdateTxRates (TxRate=24, RtsRate=24, BasicRateBitmap=0x015f) MlmeUpdateTxRates (MlmeTransmit=0x0, MinHTPhyMode=0, MaxHTPhyMode=0x4004, HTPhyMode=0x4004) MlmeUpdateHtTxRates===> !!! LINK UP !! (StaActive.bHtEnable =0, ) NDIS_STATUS_MEDIA_CONNECT Event B!.BACapability = 3024040. ClientStatusFlags = 0 RTMPSetLED::Mode=1,HighByte=0x60,LowByte=0x01 Txburst 2 !!!pAd->bNextDisableRxBA= 0 not supports 20/40 BSS COEX !!! pAd->CommonCfg.bBssCoexEnable 1 !!! pAd->CommonCfg.Channel 6 !!! pAd->StaActive.SupportedHtPhy.bHtEnable 0 !!! pAd->MlmeAux.ExtCapInfo.BssCoexstSup 0 !!! pAd->CommonCfg.CentralChannel 4 !!! pAd->CommonCfg.PhyMode 0 !!! CNTL - Association successful on BSS #0 SYNC - AP changed N OperaionMode to 3 Receive EAPOL-Key frame, TYPE = 3, Length = 117 MediaState is connected Receive EAPOL-Key frame, TYPE = 3, Length = 175 rt_ioctl_siwencodeext::DefaultKeyId = 0 AsicAddSharedKeyEntry BssIndex=0, KeyIdx=0 AsicAddSharedKeyEntry: AES key #0 Key = 40:cd:5b:dc:09:fa:a4:82:eb:d5:bc:7c:24:2d:de:29 Rx MIC Key = 00:00:00:00:00:00:00:00 Tx MIC Key = 00:00:00:00:00:00:00:00 Read: SHARED_KEY_MODE_BASE at this Bss[0] KeyIdx[0]= 0x0 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x4 AsicUpdateWCIDIVEIV: wcid(1) 0x20000001, 0x00000000 AsicUpdateWcidAttributeEntry : WCID #1, KeyIndex #0, Alg=AES WCIDAttri = 0x8 rt_ioctl_siwencodeext::IW_ENCODE_ALG_TKIP - keyIdx = 2, ext->key_len = 32 AsicAddSharedKeyEntry BssIndex=0, KeyIdx=2 AsicAddSharedKeyEntry: TKIP key #2 Key = 87:62:e9:bc:93:bc:a1:52:e8:6c:d9:c2:d8:01:26:a6 Rx MIC Key = f6:06:ad:01:6f:7c:49:29 Tx MIC Key = de:df:ee:72:f3:bf:02:23 Read: SHARED_KEY_MODE_BASE at this Bss[0] KeyIdx[2]= 0x4 Write: SHARED_KEY_MODE_BASE at this Bss[0] = 0x304 # SYNC - send NULL Frame @24 Mbps... wpa_cli reconnect Using interface 'wlan0' Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory # SYNC - send NULL Frame @24 Mbps... # SYNC - send NULL Frame @24 Mbps... SYNC - send NULL Frame @24 Mbps... # wpa_cli scan_results Using interface 'wlan0' Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory # SYNC - send NULL Frame @24 Mbps... # wpa_cli list_netSYNC - send NULL Frame @24 Mbps... works Using interface 'wlan0' Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory # SYNC - send NULL Frame @24 Mbps... > > how does your wpa_cli scan_results and wpa_cli list_networks look like ? > Is your AP hidden ? > > The settings list of networks is just a merge of configured networks and > scanned results. Duplicate networks indicate there are duplicate configured > networks (probably came when you added more networks with existing out of > range networks). > > An out of range network indicates scan results are probably failing. > > I also see failures where the WifiMonitor seems to be failing to establish > a connection to the wpa_supplicant, but this could be a temporary failure > before it re-establishing connection. > I/WifiHW ( 969): Interface name = /data/system/wpa_supplicant/wlan0 > E/WifiHW ( 969): Unable to open connection to supplicant on > "/data/system/wpa_supplicant/wlan0": No such file or directory > Yes, this is a temporary failure. It is able to reconnect on a subsequent attempt, as you will be able to see from the logs. Elvis Dowson -- unsubscribe: [email protected] website: http://groups.google.com/group/android-porting
