android-2.2.1 cannot get AP SSID after wifi restart

385 views

Skip to first unread message

Elvis Dowson

unread,

Nov 23, 2010, 1:31:46 PM11/23/10

to android-porting

Hi,
I'm having an issue with android-2.2.1 where wifi cannot get AP
SSID after turning off and turn on the wifi from the settings control
panel.

I'm using wpa_supplicant_6 from the android-2.2.1_r1 release.

I've been struggling with this issue for the past 4 weeks and tried
various combinations of wpa_supplicant, e.g. 0.5.10 from the
android-1.5r3 release where it used to work fine.

With android-2.2.1, and any of the wpa_supplicant releases, it doesn't
detect the SSID if you turn off and turn the wifi back on.

If you try to manually associate with the AP the second time around,
by manually entering the SSID (Olympus2 in my case), it connects
immediately. The same goes for a full system reboot, it connects to
the AP automatically after a full system restart.

However, if you just turn off and turn back the wifi on, it doesn't
automatically associate with the AP.

I am using a Ralink RT3070USB wifi module, with a gumstix Overo Earth
(TI OMAP 3503) module. Another friend who is working on a similar
platform called the AI Touchbook is also experiencing the same issue.
I have seen numerous other postings on many other forums with people
with Motorola Droid etc, having the same issue with android-2.2.

This is probably something in the android-2.2 code base in the layers
above the wpa_supplicant, perhaps with WifiManager or WifiService?

Could you please help me troubleshoot this issue?

Here is an excerpt from logcat, from the point that I turn wifi back
on the second time:

connect to supplicant done
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX
D/wpa_supplicant( 1352): >>>. DRIVER AWEXT RSSI
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED
D/wpa_supplicant( 1352): Link Speed command
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWSTATS]: Operation
not supported on transport endpoint
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd MACADDR
V/WifiStateTracker( 969): Connection to supplicant established,
state=SCANNING
D/NetworkStateTracker( 969): setDetailed state, old =DISCONNECTED and
new state=SCANNING
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd RXFILTER-
ADD 0
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd BTCOEXSCAN-
STOP
D/ConnectivityService( 969): Dropping ConnectivityChange for WIFI:
DISCONNECTED/SCANNING
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWRATE]: Network is
down
INFO::Network is down!
D/wpa_supplicant( 1352): Scan timeout - try to get results
D/wpa_supplicant( 1352): Failed to get scan results
D/wpa_supplicant( 1352): Failed to get scan results - try scanning
again
D/wpa_supplicant( 1352): Setting scan request: 1 sec 0 usec
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWSCAN]: Network is
down
D/wpa_supplicant( 1352): StartinINFO::Network is down!
g AP scan (broadcast SSID)
D/wpa_supplicant( 1352): wpa_driver_wext_scan: specific scan = 0
D/wpa_supplicant( 1352): Scan requested (ret=-1) - scan timeout 5
seconds
W/wpa_supplicant( 1352): Failed to initiate AP scan.
D/wpa_supplicant( 1352): Setting scan request: 10 sec 0 usec
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCSIWSCAN]: Network is
down
D/wpa_supplicant( 1352): AWEXT: INFO::Network is down!
wpa_driver_priv_driver_cmd SCAN-ACTIVE
D/wpa_supplicant( 1352): Scan Active command
D/wpa_supplicant( 1352): Setting scan request: 0 sec 0 usec
D/wpa_supplicant( 1352): Starting AP scan (broadcast SSID)
D/wpa_supplicant( 1352): wpa_driver_wext_scan: specific scan = 0
D/wpa_supplicant( 1352): Scan requested (ret=-1) - scan timeout 5
seconds
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCSIWSCAN]: Network is
down
W/wpa_supplicant( 1352): Failed to initiate AP scan.
D/wpa_supplicant( 1352): Setting scan request: 10 sec 0 usec
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd SCAN-
PASSIVE
D/wpa_supplicant( 1352): Scan Passive command
INFO::Network is down!
D/wpa_supplicant( 1352): Scan timeout - try to get results
D/wpa_supplicant( 1352): Failed to get scan results
D/wpa_supplicant( 1352): Failed to get scan results - try scanning
again
D/wpa_supplicant( 1352): Setting scan request: 1 sec 0 usec
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWSCAN]: Network is
down
D/wpa_supplicant( 1352): AWEXT: INFO::Network is down!
wpa_driver_priv_driver_cmd SCAN-ACTIVE
D/wpa_supplicant( 1352): Scan Active command
D/wpa_supplicant( 1352): Setting scan request: 0 sec 0 usec
D/wpa_supplicant( 1352): Starting AP scan (broadcast SSID)
D/wpa_supplicant( 1352): wpa_driver_wext_scan: specific scan = 0
D/wpa_supplicant( 1352): Scan requested (ret=-1) - scan timeout 5
seconds
W/wpa_supplicant( 1352): Failed to initiate AP scan.
D/wpa_supplicant( 1352): Setting scan request: 10 sec 0 usec
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd SCAN-
PASSIVE
D/wpa_supplicant( 1352): Scan Passive command
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCSIWSCAN]: Network is
down
INFO::Network is down!
D/wpa_supplicant( 1352): Scan timeout - try to get results
D/wpa_supplicant( 1352): Failed to get scan results
D/wpa_supplicant( 1352): Failed to get scan results - try scanning
again
D/wpa_supplicant( 1352): Setting scan request: 1 sec 0 usec
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWSCAN]: Network is
down
D/wpa_supplicant( 1352): AWEXT: INFO::Network is down!
wpa_driver_priv_driver_cmd SCAN-ACTIVE
D/wpa_supplicant( 1352): Scan Active command
D/wpa_supplicant( 1352): Setting scan request: 0 sec 0 usec
D/wpa_supplicant( 1352): Starting AP scan (broadcast SSID)
D/wpa_supplicant( 1352): wpa_driver_wext_scan: specific scan = 0
D/wpa_supplicant( 1352): Scan requested (ret=-1) - scan timeout 5
seconds
W/wpa_supplicant( 1352): Failed to initiate AP scan.
D/wpa_supplicant( 1352): Setting scan request: 10 sec 0 usec
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd SCAN-
PASSIVE
D/wpa_supplicant( 1352): Scan Passive command
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCSIWSCAN]: Network is
down

Best regards,

Elvis Dowson

Irfan Sheriff

unread,

Nov 23, 2010, 8:34:16 PM11/23/10

to elvis....@gmail.com, android-porting

However, if you just turn off and turn back the wifi on, it doesn't
automatically associate with the AP.

You need to have more debugging enabled in the framework (WifiService & WifiStateTracker) to understand what is happening in the framework.

Log the sequence of driver commands issued to the wpa_supplicant to further figure out if there is something wrong.

state=SCANNING
D/NetworkStateTracker( 969): setDetailed state, old =DISCONNECTED and
new state=SCANNING
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd RXFILTER-
ADD 0
D/wpa_supplicant( 1352): AWEXT: wpa_driver_priv_driver_cmd BTCOEXSCAN-
STOP
D/ConnectivityService( 969): Dropping ConnectivityChange for WIFI:
DISCONNECTED/SCANNING
I//system/bin/wpa_supplicant( 1351): ioctl[SIOCGIWRATE]: Network is
down
INFO::Network is down!
D/wpa_supplicant( 1352): Scan timeout - try to get results
D/wpa_supplicant( 1352): Failed to get scan results
D/wpa_supplicant( 1352): Failed to get scan results - try scanning
again

Look at why these failures are happening. why are scans failing ? These failures seem to repeat in the rest of the log.

How is it showing up in the UI. Is the network getting disabled ? Do you see scan results ? can you select and associate instead of entering the AP details ?

G2

unread,

Nov 24, 2010, 1:33:52 AM11/24/10

to android-porting

I'm experiencing the same problem. Note that I have tried both
wpa_supplicant 5 and 6 with AWEXT or WEXT driver. So it's definitely a
problem in the upper stack of Android.

When the disconnection occurs, the wifi stops too. It means that the
framework is sending to the driver through wpa_supplicant a stop
command.

But if I enter a SSID that exists on the wireless network, the
framework manages to restart the dongle! But even if I stop/restart
the wifi through the UI (even after an rmmod of the driver), it won't
scan anymore until the next reboot.

More info here:
http://bugzilla.alwaysinnovating.com/show_bug.cgi?id=157

Note that it's also related to this bug:
http://groups.google.com/group/android-porting/browse_thread/thread/abb7410a2272f2c/0e413a5b461959f4?lnk=gst&q=wifi++gregoire#0e413a5b461959f4

Grégoire

Elvis Dowson

unread,

Nov 24, 2010, 11:30:46 AM11/24/10

to Irfan Sheriff, android-porting, Dmitry Shmidt, Gregoire Gentil

Hi Irfan,

I noticed something weird after I scrolled the scanned AP list. My AP SSID is Olympus2. When I scrolled down the list I saw an additional Olympus2, and another misspelt Olyympus2 (extra y in the SSID name)! This looks like a bug in the scan buffer list.

On Wed, Nov 24, 2010 at 5:34 AM, Irfan Sheriff <ishe...@gmail.com> wrote:

You need to have more debugging enabled in the framework (WifiService & WifiStateTracker) to understand what is happening in the framework.

Log the sequence of driver commands issued to the wpa_supplicant to further figure out if there is something wrong.

I'm attaching the log output. It shows it from start with attempt 1, which connects to wifi successfully. With attempt 2, it doesn't connect automatically. Search for the "Comment" keyword, to jump from attempt 1 and attempt 2.

Look at why these failures are happening. why are scans failing ? These failures seem to repeat in the rest of the log.

How is it showing up in the UI. Is the network getting disabled ? Do you see scan results ? can you select and associate instead of entering the AP details ?

I have attached pictures of the various screens. I've renamed the files accordingly.

I can see scan results the first time AP SSID Olympus, plus an duplicate SSID (Olympus2) and a misspelt variant of my AP SSID (Olyympus2) with an extra y in the name.

The second time around after turning off and turning the wifi back on, wifi is on, but it doesn't show the scan results, so I cannot select and associate the second time around. At this stage, I have to manually enter the AP SSID, and it connects to the AP, but there are also additional misspelt SSIDs, and it got the IP address.

If I repeat the whole process a second time, after doing a cold boot, after turning off and turning the wifi back on, and manually associating with the AP, it connects to the AP, but it gets stuck trying to obtain an IP address, and after sometime disconnects, and then tries again in a loop. I haven't captured a log after rebooting the system, but can do so if you need it.

If we can fix the first issue with the duplicate and mis-spelt AP SSID names it would be great.

Best regards,

Elvis Dowson

01 - Attemp 01 - Successfully connected to AP SSID Olympus.JPG

02 - Attempt 01 - Scroll the list of scanned APs results in additional duplicate AP SSID and misspelt AP SSID.JPG

03 - Attempt 01 - Turn off wifi.JPG

04 - Attempt 02 - Turn wifi back on.JPG

05 - Attempt 02 - Manually enter AP SSID Olympus2.JPG

201011241930-android-2.2.1-wifi-restart-not-working.log

06 - Attempt 02 - Connecting to AP with duplicate and misspelt AP names.JPG

07 - Attempt 02 - Connected to AP Olympus 2.JPG

08 - Attempt 02- Trying to obtain IP address second time around.JPG

Elvis Dowson

unread,

Nov 24, 2010, 2:56:37 PM11/24/10

to Irfan Sheriff, android-porting, Dmitry Shmidt, Gregoire Gentil

Hi Irfan,

For the previous run, I had made one change which for some reason cause the extra y to appear in the AP SSID.

I just reverted the change, it was done to WifiStateTracker.java. However, still I get a bunch of duplicate AP SSIDs in the list of scanned APs.

diff --git a/wifi/java/android/net/wifi/WifiStateTracker.java b/wifi/java/android/net/wifi/WifiStateTracker.java

index 91f965b..5473719 100644

--- a/wifi/java/android/net/wifi/WifiStateTracker.java

+++ b/wifi/java/android/net/wifi/WifiStateTracker.java

@@ -1076,7 +1076,7 @@ public class WifiStateTracker extends NetworkStateTracker {

* On receiving the first scan results after connecting to

* the supplicant, switch scan mode over to passive.

- setScanMode(false);

+ setScanMode(true);

break;

case EVENT_POLL_INTERVAL:

I have attached a second debug log. This contains comments that delineates what happens at each step:

Attempt 01 = First wifi AP association, get IP address and wifi connected automatically. Turn off wifi.

Attempt 02 = Turn wifi back on, but doesn't associate automatically. Manually enter AP SSID, and it connects automatically and gets the IP address.

This log also contains the logcat output after a full system reboot. The behaviour is the same as above, i.e. the behaviour is consistently reproduceable.

Best regards,

Elvis Dowson

09 - Attempt 01 - Duplicate AP SSID after first association.JPG

10 - Attempt 02 - Duplicate AP SSIDs during second association after wifi restart.JPG

11 - Attempt 02 - AP list initial.JPG

12 - Attempt 02 - AP list after scrolling down showing duplicate SSIDs.JPG

14 - Attempt 02 - AP list after successfully connecting after entering SSID manually but still has duplicate SSIDs.JPG

201011242330-android-2.2.1-wifi-does-not-connect-automatically-to-AP-after-restarting-from-settings-control-panel.log

Elvis Dowson

unread,

Nov 24, 2010, 9:23:44 PM11/24/10

to android-porting

Hi,
In summary, what I can observe is as follows:

a. First AP association attempt works fine, and I'm able to browse the
internet. However, an extra AP with the same SSID gets displayed in

the list of scanned APs.

b. After turning off and turning back the wifi on from the settings
control panel, the system tries to scan but does not display any AP
SSIDs. It also doesn't automatically associate with the previously
associated SSID.

If you manually enter the AP SSID, it immediately connects, however,
it displays additional duplicate AP SSIDs shown in image "10 - Attempt
02 - Duplicate AP SSIDs during second association after wifi
restart.jpg". If you wait and give it some more time, it keeps
scanning, and if you keep scrolling the scanned AP list, it keeps
adding and removing AP SSIDs, some actual ones around (neighbours
SSIDs which are very weak, and disappear quickly), and a lot of
duplicate AP SSIDs (i.e. mutilple AP SSIDs with name Olympus2), as
shown in image 11, 12 & 14.

How can I troubleshoot this issue and get android wifi to connect
automatically to the AP after turning off and turning the wifi back
on?

Elvis Dowson

Irfan Sheriff

unread,

Nov 26, 2010, 12:07:00 AM11/26/10

to elvis....@gmail.com, android-porting

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.

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

Find out the exact sequence of supplicant commands from the framework with the first attempt as compared to the second attempt. Try that on the wpa_cli to see if its a framework issue or one with driver/supplicant interaction.

Irfan

Elvis Dowson

--
unsubscribe: android-porti...@googlegroups.com
website: http://groups.google.com/group/android-porting

Elvis Dowson

unread,

Nov 26, 2010, 1:08:43 AM11/26/10

to Irfan Sheriff, android-porting

Hi Irfan,

On Fri, Nov 26, 2010 at 9:07 AM, Irfan Sheriff <ishe...@gmail.com> 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-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...

# 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

unread,

Nov 26, 2010, 1:28:35 AM11/26/10

to Irfan Sheriff, android-porting

Hi Irfan,

On Fri, Nov 26, 2010 at 9:07 AM, Irfan Sheriff <ishe...@gmail.com> wrote:

Find out the exact sequence of supplicant commands from the framework with the first attempt as compared to the second attempt. Try that on the wpa_cli to see if its a framework issue or one with driver/supplicant interaction.

I found out a specific difference that might narrow down the cause.

In my init.rc, I have defined a service called ifcfg_ralink to run ifconfig to bring up the wlan0 interface:

service ifcfg_ralink /system/bin/ifconfig wlan0 up

group system wifi

disabled

oneshot

For testing this, I switched off wifi, and rebooted the device. This causes the device to start without automatically attempting to reconnect wifi and connecting to the AP.

I noticed service ifcfg_ralink executing, after which it started executing service wpa_supplicant:

init: process 'wlan_loader', pid 1219 exited

init: starting 'ifcfg_ralink'

init: waitpid returned pid 1226, status = 00000000

init: process 'ifcfg_ralink', pid 1226 exited

SYNC - End of SCAN, restore to channel 1, Total BSS[01]

SCAN done, resume MSDU transmission ...

init: starting 'wpa_supplicant'

Driver auto reconnect to last OID_802_11_SSID setting - , len - 0

I think when I gave the wpa_cli reconnect command in the previous attempt, it gave the following error probably because I didn't run service ifcfg_ralink for bringing the wlan0 interface up:

Using interface 'wlan0'

Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory

So, during reconnect, I probably need an extra command to be issued to bring up the wlan0 interface:

# insmod rt3070sta.ko

# setprop ctl.start ifcfg_ralink

# setprop ctl.start wpa_supplicant

# wpa_cli reconnect

I'll try that out and see if it works.

Elvis Dowson

unread,

Nov 26, 2010, 9:07:49 AM11/26/10

to Irfan Sheriff, android-porting

Hi,

I tried the following commands, after turning off wifi from the GUI, and issued the following commands using the debug console to bring the interface up:

# insmod rt3070sta.ko
# setprop ctl.start ifcfg_ralink
# setprop ctl.start wpa_supplicant
# wpa_cli reconnect

exits with the following error:

Using interface 'wlan0'

Failed to connect to wpa_supplicant - wpa_ctrl_open: No such file or directory

Here is the output of the debug console (I have copy pasted the logcat messages further down, these are the standard console output messages when running the setprop ctl.start wpa_supplicant and wpa_cli reconnect commands:

init: starting 'wpa_supplicant'

# # ===> rt_ioctl_siwpmksa

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[02]

SCAN done, resume MSDU transmission ...

===>rt_ioctl_giwscan. 2(2) BSS returned, data->length = 371

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 2 BSS match the desire (8)SSID - Olympus2

IOCTL::SIOCSIWAP 68:7f:74:1c:e4:7c

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: d360b674, len = 26

Key = ab:6d:b1:7a:f0:cd:78:15:21:ab:71:60:af:bc:ee:40

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 = ab:29:ae:18:7f:3d:41:42:52:a6:22:16:85:c7:57:a3

Rx MIC Key = 65:ac:d6:b7:31:76:24:04

Tx MIC Key = 4c:7b:b2:98:f5:fd:50:ba

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...

SYNC - send NULL Frame @24 Mbps...

# SYNC - send NULL Frame @24 Mbps...

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

# # BEACON lost > 512 msec with TxOkCnt=0 -> CQI=0

MMCHK - No BEACON. Dead CQI. Auto Recovery attempt #0

!!! LINK DOWN !!!

!!! LINK DOWN 2!!!

MacTableDeleteEntry1 - Total= 0

CmdThread : CMDTHREAD_SET_ASIC_WCID : WCID = 1, SetTid = ffffffff, DeleteTid = ffffffff.

AsicSetEdcaParm

1-MACValue= 0,

2-MACValue= 0,

RTMPSetLED::Mode=1,HighByte=0x20,LowByte=0x01

--->Disable TSF synchronization

LinkDownCleanMlmeAux.ExtCapInfo!

The output from logcat for the first attempt (ie. turn on wifi through GUI, connection established and then turn off wifi) is as follows:

I/WifiHW ( 966): Loading WiFi modules

I/WifiHW ( 966): WIFI DRIVER_MODULE_NAME := rt3070sta,

I/WifiHW ( 966): WIFI DRIVER_MODULE_TAG := rt3070sta ,

I/WifiHW ( 966): WIFI DRIVER_MODULE_PATH := /system/lib/modules/rt3070sta.ko,

E/WifiHW ( 966): cannot find driver rt3070sta in proc

D/dalvikvm( 966): GC_FOR_MALLOC freed 8985 objects / 414080 bytes in 102ms hsize: 16777216

D/dalvikvm( 1058): GC_FOR_MALLOC freed 3442 objects / 214984 bytes in 71ms hsize: 16777216

D/Tethering( 966): wlan0 is not a tetherable iface, ignoring

I/WifiHW ( 966): Wi-Fi is running

D/WifiService( 966): ACTION_BATTERY_CHANGED pluggedType: 1

I/WifiHW ( 966): Interface directory = /data/system/wpa_supplicant

I/WifiHW ( 966): Interface name = /data/system/wpa_supplicant/wlan0

E/WifiHW ( 966): Unable to open connection to supplicant on "/data/system/wpa_supplicant/wlan0": No such file or directory

D/wpa_supplicant( 1232): Initializing interface 'wlan0' conf '/data/misc/wifi/wpa_supplicant.conf' driver 'awext' ctrl_interface 'N/A' bridge 'N/A'

D/wpa_supplicant( 1232): Configuration file '/data/misc/wifi/wpa_supplicant.conf' -> '/data/misc/wifi/wpa_supplicant.conf'

D/wpa_supplicant( 1232): Reading configuration file '/data/misc/wifi/wpa_supplicant.conf'

D/wpa_supplicant( 1232): ctrl_interface='DIR=/data/system/wpa_supplicant GROUP=wifi'

D/wpa_supplicant( 1232): update_config=1

D/wpa_supplicant( 1232): Priority group 1

D/wpa_supplicant( 1232): id=0 ssid='Olympus2'

D/wpa_supplicant( 1232): Initializing interface (2) 'wlan0'

D/wpa_supplicant( 1232): SIOCGIWRANGE: WE(compiled)=22 WE(source)=14 enc_capa=0xf

D/wpa_supplicant( 1232): capabilities: key_mgmt 0xf enc 0xf flags 0x0

D/wpa_supplicant( 1232): WEXT: Operstate: linkmode=1, operstate=5

D/wpa_supplicant( 1232): Own MAC address: 00:08:10:74:b5:da

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0

D/wpa_supplicant( 1232): wpa_driver_awext_set_countermeasures

D/wpa_supplicant( 1232): wpa_driver_awext_set_drop_unencrypted

D/wpa_supplicant( 1232): RSN: flushing PMKID list in the driver

D/wpa_supplicant( 1232): Setting scan request: 0 sec 100000 usec

D/wpa_supplicant( 1232): EAPOL: SUPP_PAE entering state DISCONNECTED

D/wpa_supplicant( 1232): EAPOL: KEY_RX entering state NO_KEY_RECEIVE

D/wpa_supplicant( 1232): EAPOL: SUPP_BE entering state INITIALIZE

D/wpa_supplicant( 1232): EAP: EAP entering state DISABLED

D/wpa_supplicant( 1232): Using existing control interface directory.

D/wpa_supplicant( 1232): ctrl_interface_group=1010 (from group name 'wifi')

D/wpa_supplicant( 1232): Added interface wlan0

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8b06 len=8

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): State: DISCONNECTED -> SCANNING

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=-1 state=2 BSSID=00:00:00:00:00:00

D/wpa_supplicant( 1232): Starting AP scan (broadcast SSID)

D/wpa_supplicant( 1232): Trying to get current scan results first without requesting a new scan to speed up initial association

D/wpa_supplicant( 1232): Failed to get scan results

D/wpa_supplicant( 1232): Failed to get scan results - try scanning again

D/wpa_supplicant( 1232): Setting scan request: 0 sec 0 usec

D/wpa_supplicant( 1232): Starting AP scan (broadcast SSID)

D/wpa_supplicant( 1232): wpa_driver_wext_scan: specific scan = 0

I//system/bin/wpa_supplicant( 1231): ioctl[SIOCGIWSCAN]: Try again

D/wpa_supplicant( 1232): Scan requested (ret=0) - scan timeout 5 seconds

I/power ( 966): *** set_screen_state 1

D/wpa_supplicant( 1232): EAPOL: disable timer tick

I/WifiHW ( 966): Interface directory = /data/system/wpa_supplicant

I/WifiHW ( 966): Interface name = /data/system/wpa_supplicant/wlan0

I/WifiHW ( 966): connect to supplicant done

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd MACADDR

V/WifiStateTracker( 966): Connection to supplicant established, state=SCANNING

D/NetworkStateTracker( 966): setDetailed state, old =IDLE and new state=SCANNING

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RXFILTER-ADD 0

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd BTCOEXSCAN-STOP

D/ConnectivityService( 966): ConnectivityChange for WIFI: DISCONNECTED/SCANNING

D/ConnectivityService( 966): getMobileDataEnabled returning true

D/DataConnectionTracker( 1034): enableApnType(default), isApnTypeActive = false and state = IDLE

D/DataConnectionTracker( 1034): type not available

D/Tethering( 966): Tethering got CONNECTIVITY_ACTION

D/Tethering( 966): MasterInitialState.processMessage what=3

E/HierarchicalStateMachine( 966): TetherMaster - unhandledMessage: msg.what=3

D/wpa_supplicant( 1232): Scan timeout - try to get results

D/wpa_supplicant( 1232): Received 371 bytes of scan results (2 BSSes)

D/wpa_supplicant( 1232): New scan results available

D/wpa_supplicant( 1232): Selecting BSS from priority group 1

D/wpa_supplicant( 1232): Try to find WPA-enabled AP

D/wpa_supplicant( 1232): 0: 68:7f:74:1c:e4:7c ssid='Olympus2' wpa_ie_len=28 rsn_ie_len=24 caps=0x11

D/wpa_supplicant( 1232): selected based on RSN IE

D/wpa_supplicant( 1232): selected WPA AP 68:7f:74:1c:e4:7c ssid='Olympus2'

I/wpa_supplicant( 1232): Trying to associate with 68:7f:74:1c:e4:7c (SSID='Olympus2' freq=2437 MHz)

D/wpa_supplicant( 1232): Cancelling scan request

D/wpa_supplicant( 1232): WPA: clearing own WPA/RSN IE

D/wpa_supplicant( 1232): Automatic auth_alg selection: 0x1

D/wpa_supplicant( 1232): RSN: using IEEE 802.11i/D9.0

D/wpa_supplicant( 1232): WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2

D/wpa_supplicant( 1232): WPA: using GTK TKIP

D/wpa_supplicant( 1232): WPA: using PTK CCMP

D/wpa_supplicant( 1232): WPA: using KEY_MGMT WPA-PSK

D/wpa_supplicant( 1232): No keys have been configured - skip key clearing

D/wpa_supplicant( 1232): wpa_driver_awext_set_drop_unencrypted

D/wpa_supplicant( 1232): State: SCANNING -> ASSOCIATING

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=-1 state=3 BSSID=68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)

D/wpa_supplicant( 1232): WEXT: Operstate: linkmode=-1, operstate=5

D/wpa_supplicant( 1232): wpa_driver_awext_associate

D/wpa_supplicant( 1232): Setting authentication timeout: 10 sec 0 usec

D/wpa_supplicant( 1232): EAPOL: External notification - EAP success=0

D/wpa_supplicant( 1232): EAPOL: External notification - EAP fail=0

D/wpa_supplicant( 1232): EAPOL: External notification - portControl=Auto

D/wpa_supplicant( 1232): RSN: Ignored PMKID candidate without preauth flag

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8b06 len=8

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8b04 len=12

D/wpa_supplicant( 1232): ap_scan = 1

V/WifiMonitor( 966): Event [Trying to associate with 68:7f:74:1c:e4:7c (SSID='Olympus2' freq=2437 MHz)]

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=-1 state=3 BSSID=68:7f:74:1c:e4:7c]

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8b1a len=16

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd SCAN-PASSIVE

D/wpa_supplicant( 1232): Scan Passive command

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='ssid'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='bssid'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'bssid'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='priority'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='scan_ssid'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='wep_tx_keyidx'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='wep_key0'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'wep_key0'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='wep_key1'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'wep_key1'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='wep_key2'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'wep_key2'

V/WifiStateTracker( 966): Changing supplicant state: SCANNING ==> ASSOCIATING

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='wep_key3'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'wep_key3'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='psk'

D/wpa_supplicant( 1232): Do not allow key_data field to be exposed

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='proto'

D/NetworkS CTRL_IFACE: GET_NETWORK id=0 name='key_mgmt'

D/ConnectivityService( 966): ConnectivityChange for WIFI: CONNECTING/CONNECTING

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='auth_alg'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='pairwise'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='group'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='eap'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'eap'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='phase2'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'phase2'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='identity'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'identity'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='anonymous_identity'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'anonymous_identity'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='password'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'password'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='client_cert'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'client_cert'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='private_key'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'private_key'

D/wpa_supplicant( 1232): CTRL_IFACE: GET_NETWORK id=0 name='ca_cert'

D/wpa_supplicant( 1232): CTRL_IFACE: Failed to get network variable 'ca_cert'

I/dalvikvm( 966): Jit: resizing JitTable from 4096 to 8192

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8c07 len=50

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/wpa_supplicant( 1232): Wireless event: cmd=0x8b15 len=20

D/wpa_supplicant( 1232): Wireless event: new AP: 68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): Association info event

D/wpa_supplicant( 1232): WPA: clearing AP WPA IE

D/wpa_supplicant( 1232): WPA: clearing AP RSN IE

D/wpa_supplicant( 1232): State: ASSOCIATING -> ASSOCIATED

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=0 state=4 BSSID=68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)

D/wpa_supplicant( 1232): WEXT: Operstate: linkmode=-1, operstate=5

D/wpa_supplicant( 1232): Associated to a new BSS: BSSID=68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): No keys have been configured - skip key clearing

I/wpa_supplicant( 1232): Associated with 68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): WPA: Association event - clear replay counter

D/wpa_supplicant( 1232): WPA: Clear old PTK

D/wpa_supplicant( 1232): EAPOL: External notification - portEnabled=0

D/wpa_supplicant( 1232): EAPOL: External notification - portValid=0

D/wpa_supplicant( 1232): EAPOL: External notification - EAP success=0

D/wpa_supplicant( 1232): EAPOL: External notification - portEnabled=1

D/wpa_supplicant( 1232): EAPOL: SUPP_PAE entering state CONNECTING

D/wpa_supplicant( 1232): EAPOL: enable timer tick

D/wpa_supplicant( 1232): EAPOL: SUPP_BE entering state IDLE

D/wpa_supplicant( 1232): Setting authentication timeout: 10 sec 0 usec

D/wpa_supplicant( 1232): Cancelling scan request

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=0 state=4 BSSID=68:7f:74:1c:e4:7c]

V/WifiStateTracker( 966): Changing supplicant state: ASSOCIATING ==> ASSOCIATED

D/NetworkStateTracker( 966): setDetailed state, old =CONNECTING and new state=CONNECTING

V/WifiMonitor( 966): Event [Associated with 68:7f:74:1c:e4:7c]

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/dalvikvm( 1034): GC_FOR_MALLOC freed 3880 objects / 230104 bytes in 238ms hsize: 16777216

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): ap_scan = 1

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd SCAN-ACTIVE

D/wpa_supplicant( 1232): Scan Active command

E/wpa_supplicant( 1232): Ongoing Scan action...

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd SCAN-PASSIVE

D/wpa_supplicant( 1232): Scan Passive command

D/wpa_supplicant( 1232): RX EAPOL from 68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): Setting authentication timeout: 10 sec 0 usec

D/wpa_supplicant( 1232): IEEE 802.1X RX: version=2 type=3 length=117

D/wpa_supplicant( 1232): EAPOL-Key type=2

D/wpa_supplicant( 1232): key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)

D/wpa_supplicant( 1232): key_length=16 key_data_length=22

D/wpa_supplicant( 1232): State: ASSOCIATED -> 4WAY_HANDSHAKE

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=0 state=5 BSSID=00:00:00:00:00:00

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=0 state=5 BSSID=00:00:00:00:00:00]

D/wpa_supplicant( 1232): WPA: RX message 1 of 4-Way Handshake from 68:7f:74:1c:e4:7c (ver=2)

D/wpa_supplicant( 1232): RSN: no matching PMKID found

D/wpa_supplicant( 1232): WPA: PTK derivation - A1=00:08:10:74:b5:da A2=68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): WPA: Sending EAPOL-Key 2/4

V/WifiStateTracker( 966): Changing supplicant state: ASSOCIATED ==> FOUR_WAY_HANDSHAKE

D/NetworkStateTracker( 966): setDetailed state, old =CONNECTING and new state=AUTHENTICATING

D/ConnectivityService( 966): Dropping ConnectivityChange for WIFI: CONNECTING/AUTHENTICATING

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): RX EAPOL from 68:7f:74:1c:e4:7c

D/wpa_supplicant( 1232): IEEE 802.1X RX: version=2 type=3 length=175

D/wpa_supplicant( 1232): EAPOL-Key type=2

D/wpa_supplicant( 1232): key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)

D/wpa_supplicant( 1232): key_length=16 key_data_length=80

D/wpa_supplicant( 1232): State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=0 state=5 BSSID=00:00:00:00:00:00

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=0 state=5 BSSID=00:00:00:00:00:00]

D/wpa_supplicant( 1232): WPA: RX message 3 of 4-Way Handshake from 68:7f:74:1c:e4:7c (ver=2)

D/wpa_supplicant( 1232): WPA: No WPA/RSN IE for this AP known. Trying to get from scan results

D/wpa_supplicant( 1232): WPA: Found the current AP from updated scan results

D/wpa_supplicant( 1232): WPA: Sending EAPOL-Key 4/4

D/wpa_supplicant( 1232): WPA: Installing PTK to the driver.

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16

V/WifiStateTracker( 966): Changing supplicant state: FOUR_WAY_HANDSHAKE ==> FOUR_WAY_HANDSHAKE

D/wpa_supplicant( 1232): EAPOL: External notification - portValid=1

D/wpa_supplicant( 1232): State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=0 state=6 BSSID=00:00:00:00:00:00

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=0 state=6 BSSID=00:00:00:00:00:00]

V/WifiStateTracker( 966): Changing supplicant state: FOUR_WAY_HANDSHAKE ==> GROUP_HANDSHAKE

D/wpa_supplicant( 1232): WPA: Installing GTK to the driver (keyidx=2 tx=0 len=32).

D/wpa_supplicant( 1232): wpa_driver_wext_set_key: alg=2 key_idx=2 set_tx=0 seq_len=6 key_len=32

I/wpa_supplicant( 1232): WPA: Key negotiation completed with 68:7f:74:1c:e4:7c [PTK=CCMP GTK=TKIP]

V/WifiMonitor( 966): Event [WPA: Key negotiation completed with 68:7f:74:1c:e4:7c [PTK=CCMP GTK=TKIP]]

D/wpa_supplicant( 1232): Cancelling authentication timeout

D/wpa_supplicant( 1232): State: GROUP_HANDSHAKE -> COMPLETED

I/wpa_supplicant( 1232): CTRL-EVENT-STATE-CHANGE id=0 state=7 BSSID=00:00:00:00:00:00

V/WifiMonitor( 966): Event [CTRL-EVENT-STATE-CHANGE id=0 state=7 BSSID=00:00:00:00:00:00]

I/wpa_supplicant( 1232): CTRL-EVENT-CONNECTED - Connection to 68:7f:74:1c:e4:7c completed (auth) [id=0 id_str=]

D/wpa_supplicant( 1232): wpa_driver_wext_set_operstate: operstate 0->1 (UP)

D/wpa_supplicant( 1232): WEXT: Operstate: linkmode=-1, operstate=6

D/wpa_supplicant( 1232): EAPOL: External notification - portValid=1

D/wpa_supplicant( 1232): EAPOL: External notification - EAP success=1

D/wpa_supplicant( 1232): EAPOL: SUPP_PAE entering state AUTHENTICATING

D/wpa_supplicant( 1232): EAPOL: SUPP_BE entering state SUCCESS

D/wpa_supplicant( 1232): EAP: EAP entering state DISABLED

D/wpa_supplicant( 1232): EAPOL: SUPP_PAE entering state AUTHENTICATED

D/wpa_supplicant( 1232): EAPOL: SUPP_BE entering state IDLE

D/wpa_supplicant( 1232): EAPOL authentication completed successfully

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])

D/wpa_supplicant( 1232): RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added

D/NetworkStateTracker( 966): setDetailed state, old =AUTHENTICATING and new state=AUTHENTICATING

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

V/WifiStateTracker( 966): Changing supplicant state: GROUP_HANDSHAKE ==> COMPLETED

V/WifiMonitor( 966): Event [CTRL-EVENT-CONNECTED - Connection to 68:7f:74:1c:e4:7c completed (auth) [id=0 id_str=]]

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

V/WifiStateTracker( 966): New network state is CONNECTED

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd BTCOEXMODE 1

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd POWERMODE 1

D/WifiStateTracker( 966): DhcpHandler: DHCP request started

D/dhcp_utils( 966): dhcp_do_request

D/NetworkStateTracker( 966): setDetailed state, old =AUTHENTICATING and new state=OBTAINING_IPADDR

D/ConnectivityService( 966): Dropping ConnectivityChange for WIFI: CONNECTING/OBTAINING_IPADDR

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/dhcpcd ( 1242): dhcpcd 4.0.15 starting

D/dhcpcd ( 1242): hardware address = 00:08:10:74:b5:da

D/dhcpcd ( 1242): executing `/system/etc/dhcpcd/dhcpcd-run-hooks', reason PREINIT

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/wpa_supplicant( 1232): ap_scan = 2

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd SCAN-ACTIVE

D/wpa_supplicant( 1232): Scan Active command

D/wpa_supplicant( 1232): Setting scan request: 0 sec 0 usec

D/wpa_supplicant( 1232): Starting AP scan (specific SSID)

D/wpa_supplicant( 1232): wpa_driver_wext_scan: specific scan = 0

D/wpa_supplicant( 1232): Scan requested (ret=0) - scan timeout 5 seconds

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd SCAN-PASSIVE

D/wpa_supplicant( 1232): Scan Passive command

I//system/bin/dhcpcd( 1241): [: not found

D/dhcpcd ( 1242): host does not support a monotonic clock - timing can skew

D/dhcpcd ( 1242): broadcasting for a lease

D/dhcpcd ( 1242): sending DHCP_DISCOVER with xid 0xefacfb42, next in 3.21 seconds

D/wpa_supplicant( 1232): EAPOL: startWhen --> 0

D/wpa_supplicant( 1232): EAPOL: disable timer tick

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd RSSI-APPROX

D/wpa_supplicant( 1232): >>>. DRIVER AWEXT RSSI

D/wpa_supplicant( 1232): AWEXT: wpa_driver_priv_driver_cmd LINKSPEED

D/wpa_supplicant( 1232): Link Speed command

D/dhcpcd ( 1242): sending DHCP_DISCOVER with xid 0xefacfb42, next in 7.86 seconds

D/dhcpcd ( 1242): offered 192.168.1.102 from 192.168.1.1

D/dhcpcd ( 1242): sending DHCP_REQUEST with xid 0xefacfb42, next in 4.55 seconds

D/dhcpcd ( 1242): acknowledged 192.168.1.102 from 192.168.1.1

D/dhcpcd ( 1242): checking 192.168.1.102 is available on attached networks

D/dhcpcd ( 1242): sending ARP probe (1 of 3), next in 1.68 seconds