972794 - [Tarako]Connect wpa supplicant consume 5 seconds

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Wifi, defect)

Description

[Xinhe Yan]

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.19 (KHTML, like Gecko) Ubuntu/11.04 Chromium/18.0.1025.151 Chrome/18.0.1025.151 Safari/535.19

Comment 1

[Xinhe Yan]

Android connect wpa_supplicant 5 times and nap is 1 second.
b2g connect wpa_supplicant 3 times and nap is 5 second.

I checked broadcom and our trout wifi chip.They both need connect wpa twice.

I prefer follow android.

WifiWorker.js
  function connectCallback(ok) {
    if (ok === 0) {
      // Tell the event worker to start waiting for events.
      retryTimer = null;
      connectTries = 0;
      didConnectSupplicant(function(){});
      return;
    }
    if (connectTries++ < 3) {
      // Try again in 5 seconds.
      if (!retryTimer)
        retryTimer = Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);

      retryTimer.initWithCallback(function(timer) {
        wifiCommand.connectToSupplicant(connectCallback);
      }, 5000, Ci.nsITimer.TYPE_ONE_SHOT);
      return;
    }

    retryTimer = null;
    connectTries = 0;
    notify("supplicantlost", { success: false });
  }

WifiMonitor.java
    private boolean connectToSupplicant() {
            int connectTries = 0;

            while (true) {
                if (WifiNative.connectToSupplicant()) {
                    return true;
                }
                if (connectTries++ < 5) {
                    nap(1);
                } else {
                    break;
                }
            }
            return false;
   }

Comment 2

[Vincent Chang[:vchang][changyihsin]]

Hi Xinhe, it definitely fine for me to modify that retry interval. But I am wonding why do we need to connect wpa_supplicatn twice in most of time ?

Comment 3

[Xinhe Yan]

(In reply to Vincent Chang[:vchang] from comment #2)
> Hi Xinhe, it definitely fine for me to modify that retry interval. But I am
> wonding why do we need to connect wpa_supplicatn twice in most of time ?

start_supplican will return after call property_set("ctl.start", daemon_cmd);. 
But between start_supplicant return and wpa_supplicant finish initialize, the time is uncertain.
Task scheduling or other factor may affect this time.

This can be verify by log.
Wpa not init before first wifi_connect_to_supplicant.

02-17 06:45:51.810 E/WifiHW  (   81): xinhe enter wifi_connect_to_supplicant
02-17 06:45:51.810 E/WifiHW  (   81): Unable to open connection to supplicant on "wlan0": No such file or directory
02-17 06:45:51.810 I/Gecko   (   81): -*- WifiWorker component: xinhe wpa connectCallback result-1

02-17 06:45:51.880 D/wpa_supplicant(  494): wpa_supplicant v0.8.x

I also test on our tiger chip(Dual CPU 1.2GHz Cortex-A5\RAM 512M ). Connect wpa_supplicant will success after start wpa.
This bug will be amplify on cheap phone.


02-17 06:45:51.800 I/Gecko   (   81): xinhe WifiUtils command start_supplicant
02-17 06:45:51.800 E/WifiHW  (   81): Leo ensure_config_file_exists config_file=/data/misc/wifi/wpa_supplicant.conf
02-17 06:45:51.800 E/WifiHW  (   81): daemon_cmd=wpa_supplicant:-iwlan0 -c/data/misc/wifi/wpa_supplicant.conf                                                
02-17 06:45:51.800 E/WifiHW  (   81): xinhe wifi_start_supplicant return 0
02-17 06:45:51.800 I/Gecko   (   81): -*- WifiWorker component: xinhe wpa started ,then send enableInterface
02-17 06:45:51.800 I/Gecko   (   81): xinhe WifiUtils command ifc_enable
02-17 06:45:51.800 I/Gecko   (   81): -*- WifiWorker component: xinhe detected SDK version then connectToSupplicant15
02-17 06:45:51.810 I/Gecko   (   81): xinhe WifiUtils command connect_to_supplicant
02-17 06:45:51.810 E/WifiHW  (   81): xinhe enter wifi_connect_to_supplicant
02-17 06:45:51.810 E/WifiHW  (   81): Unable to open connection to supplicant on "wlan0": No such file or directory
02-17 06:45:51.810 I/Gecko   (   81): -*- WifiWorker component: xinhe wpa connectCallback result-1
02-17 06:45:51.880 D/wpa_supplicant(  494): wpa_supplicant v0.8.x
02-17 06:45:51.880 D/wpa_supplicant(  494): random: Trying to read entropy from /dev/random
02-17 06:45:51.880 D/wpa_supplicant(  494): Initializing interface 'wlan0' conf '/data/misc/wifi/wpa_supplicant.conf' driver 'nl80211' ctrl_interface 'N/A' bridge 'N/A'
02-17 06:45:51.880 D/wpa_supplicant(  494): Configuration file '/data/misc/wifi/wpa_supplicant.conf' -> '/data/misc/wifi/wpa_supplicant.conf'
02-17 06:45:51.880 D/wpa_supplicant(  494): Reading configuration file '/data/misc/wifi/wpa_supplicant.conf'
02-17 06:45:51.880 D/wpa_supplicant(  494): ctrl_interface='/data/system/wpa_supplicant'
02-17 06:45:51.880 D/wpa_supplicant(  494): update_config=1
02-17 06:45:51.880 D/wpa_supplicant(  494): Line: 5 - start of a new network block
02-17 06:45:51.890 D/wpa_supplicant(  494): key_mgmt: 0x4
02-17 06:45:51.890 D/wpa_supplicant(  494): priority=1 (0x1)
02-17 06:45:51.890 D/wpa_supplicant(  494): Line: 11 - start of a new network block
02-17 06:45:51.890 D/wpa_supplicant(  494): key_mgmt: 0x1
02-17 06:45:51.890 D/wpa_supplicant(  494): priority=2 (0x2)
02-17 06:45:51.890 D/wpa_supplicant(  494): Priority group 2
02-17 06:45:51.890 D/wpa_supplicant(  494):    id=1 ssid='CMCC-AUTO'
02-17 06:45:51.890 D/wpa_supplicant(  494): Priority group 1
02-17 06:45:51.890 D/wpa_supplicant(  494):    id=0 ssid='CMCC'
02-17 06:45:51.890 D/wpa_supplicant(  494): nl80211: interface wlan0 in phy phy1

02-17 06:45:52.810 I/Gecko   (   81): xinhe WifiUtils command connect_to_supplicant
02-17 06:45:52.810 E/WifiHW  (   81): xinhe enter wifi_connect_to_supplicant                                                                                 
02-17 06:45:52.820 I/Gecko   (   81): -*- WifiWorker component: xinhe wpa connectCallback result0

Comment 4

[Vincent Chang[:vchang][changyihsin]]

Start wpa_supplicant command in wifi.c has checked the status of init.svc.wpa_supplicant after doing the property_set("ctl.start", daemon_cmd). 
http://androidxref.com/4.0.4/xref/hardware/libhardware_legacy/wifi/wifi.c#522

So the status running doesn't means wpa_supplicant is ready for accept a connection ? 
We don't need to modify the retry timer if we can guarantee this. Does it make sense to you ?

Comment 5

[Xinhe Yan]

(In reply to Vincent Chang[:vchang] from comment #4)
> Start wpa_supplicant command in wifi.c has checked the status of
> init.svc.wpa_supplicant after doing the property_set("ctl.start",
> daemon_cmd). 
> http://androidxref.com/4.0.4/xref/hardware/libhardware_legacy/wifi/wifi.c#522
> 
> So the status running doesn't means wpa_supplicant is ready for accept a
> connection ? 
status running doesn't means wpa already init

02-25 04:50:34.580 E/WifiHW  (   82): daemon_cmd=wpa_supplicant:-iwlan0 -c/data/misc/wifi/wpa_supplicant.conf
02-25 04:50:34.580 E/WifiHW  (   82): wifi_start_supplicant_common start wpa_supplicant and wait for running
02-25 04:50:34.580 E/WifiHW  (   82): count is 199
02-25 04:50:34.580 E/WifiHW  (   82): get wpa status running
02-25 04:50:34.590 E/WifiHW  (   82): Unable to open connection to supplicant on "wlan0": No such file or directory
02-25 04:50:34.720 D/wpa_supplicant( 3519): wpa_supplicant v0.8.x

Unable to open connection to supplicant on "wlan0"
This log came from wifi_connect_to_supplicant. But system never get a chance to start wpa.

Hamachi use different wifi.c
wifi_start_supplicant_common wait wifi.wpa_supp_ready and return.

caf log:

07-09 22:23:31.219 E/WifiHW  (  136): enter wifi_start_supplicant_common 
07-09 22:23:31.219 E/WifiHW  (  136): start wpa_supplicant
07-09 22:23:31.219 E/WifiHW  (  136): wpa status running
07-09 22:23:31.319 D/wpa_supplicant(  460): wpa_supplicant v2.0-devel-4.0.4.0.4.0.4
07-09 22:23:31.559 E/WifiHW  (  136): return 0 in wifi_start_supplicant_common
07-09 22:23:31.569 E/WifiHW  (  136): wifi_connect_to_supplicant

Comment 6

[James Ho]

Vincent, any update? It's been open for a while.

Comment 7

[Vincent Chang[:vchang][changyihsin]]

Per comment 4, I still think that it's better to optimize this in wpa_supplicant or wifi.c in libhardware_legacy. I'll post a patch soon.

Comment 8

[Vincent Chang[:vchang][changyihsin]]

Attachment: wifi.v1.0.patch

Follow the Android to reconnect to wpa_supplicant.

Comment 9

[Vincent Chang[:vchang][changyihsin]]

Hi Xinhe, can you help to double check if this patch improve the wifi startup time ?

Comment 10

[Xinhe Yan]

Thanks Vincent, this patch will decrease 4 seconds.

Comment 11

[Chuck Lee [:chucklee, Triggered by NI, Review, and Feedback requests]]

Comment on attachment 8387520 [details] [diff] [review]
wifi.v1.0.patch

Review of attachment 8387520 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good, Thanks.

I think we can open a follow up bug to move all these constants to property, so partners can optimize them for different devices without changing gecko code.

Comment 12

[Vincent Chang[:vchang][changyihsin]]

https://hg.mozilla.org/integration/b2g-inbound/rev/e3f743545ef1

Comment 13

[Vincent Chang[:vchang][changyihsin]]

Nominate for 1.3T because this fix is mainly for Tarako.

Comment 14

[Steven Yang [:styang]]

Hi Ying, please uplift the patch to v1.3T. Thanks!

Comment 15

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/e3f743545ef1

Comment 16

[[:fabrice] Fabrice Desré]

https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/bdbedf19166a