897871 - Wifi - Improve wifi startup time.

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Wifi, defect)

Description

[zhangdapeng]

User Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; TCO_20130725132343)

Steps to reproduce:

toggle wifi on/off


Actual results:

the network list shows at least 10 seconds  ,it is too slow


Expected results:

network list shows faster

Comment 1

[zhangdapeng]

this bug is serious，please solve it as soon as possible

Comment 2

[Vincent Chang[:vchang][changyihsin]]

(In reply to zhangdapeng from comment #1)
> this bug is serious，please solve it as soon as possible

May I know your expectation ? How long is acceptable ?

Comment 3

[zhangdapeng]

(In reply to Vincent Chang[:vchang] from comment #2)
> (In reply to zhangdapeng from comment #1)
> this bug is serious，please solve
> it as soon as possible

May I know your expectation ? How long is acceptable
> ?



from the setting interface （toggle the wifi checkbox on to open the wifi）  to call the HAl ，load  WIfI drive needs about 8 seconds，this delay is too long ，
this progress can be optimized，thanks (In reply to Vincent Chang[:vchang] from comment #2)
> (In reply to zhangdapeng from comment #1)
> this bug is serious，please solve
> it as soon as possible

May I know your expectation ? How long is acceptable
> ?

Comment 4

[zhangdapeng]

(In reply to zhangdapeng from comment #3)
> (In reply to Vincent Chang[:vchang] from comment #2)
> (In reply to
> zhangdapeng from comment #1)
> this bug is serious，please solve
> it as soon
> as possible

May I know your expectation ? How long is acceptable
> ?


> from the setting interface （toggle the wifi checkbox on to open the wifi） 
> to call the HAl ，load  WIfI drive needs about 8 seconds，this delay is too
> long ，
this progress can be optimized，thanks (In reply to Vincent
> Chang[:vchang] from comment #2)
> (In reply to zhangdapeng from comment #1)
> > this bug is serious，please solve
> it as soon as possible

May I know your
> expectation ? How long is acceptable
> ?

this basement code in the Android, from open the wifi, to connection to the AP, general 3,4s.

Comment 5

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch v1.0 for mc

I verified the patch on unagi. I found the stopDhcp function may block the wifi startup procedure. I will verify the patch on more phones later.

Comment 6

[Blake Kaplan (:mrbkap) (inactive)]

Comment on attachment 782518 [details] [diff] [review]
Patch v1.0 for mc

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

I'm fine with this but with one major comment addressed, please avoid copy/pasting code. Another place to look for speedups is the wait after we load the driver -- we might be able to reduce the amount of time we wait (or, even better, find some way for the driver to notify us when it's actually fully loaded).

::: dom/wifi/WifiWorker.js
@@ +708,1 @@
>    function stopDhcp(ifname, callback) {

This function basically copy/pastes killSupplicant. Can you factor out the common logic (which is everything except one property name and one property value)?

Comment 7

[zhangbaisheng]

we have checked that there are two issues which slow down the wifi turn on produce: 
1. The uplayer loads wifi driver too late after toggling the wifi checkbox on. It's about 8s from toggling the wifi checkbox on to loading the wifi driver. And do you mean it's the stopDhcp() function problem? I think stopDhcp()should be called when turning wifi off. It should not be the reason of slowing down the wifi turn on preduce.

2. wpa_supplicant is started 2s after wifi driver loaded. It should be optimized. The return value is 0 when wifi_load_driver() of Android HAL layer is called if wifi driver loaded successfully. And also the property value of "wlan.driver.status" is "ok" after wifi driver loaded. It can be the way of checking wifi driver is loaded or not.

Comment 8

[Ivan Tsay (:ITsay)]

Baisheng, is this bug from the recent testing of your v1.1 build? Need to ensure it and link it to the v1.1 meta bug. I am asking because I don't see the keyword "zffos1.1" in the title of this bug.

Comment 9

[Vincent Chang[:vchang][changyihsin]]

(In reply to zhangbaisheng from comment #7)
> we have checked that there are two issues which slow down the wifi turn on
I am wondering if you have a patch on hand ? It would be very nice if you can 
post the patch for review. 

> produce: 
> 1. The uplayer loads wifi driver too late after toggling the wifi checkbox
> on. It's about 8s from toggling the wifi checkbox on to loading the wifi
> driver. And do you mean it's the stopDhcp() function problem? I think
> stopDhcp()should be called when turning wifi off. It should not be the
> reason of slowing down the wifi turn on preduce.
The patch improves the wifi startup time on the unagi. Is it possible to verify the patch in your environment ? The stopDhcp() will be called when wifi is enabled in current code base.  

> 2. wpa_supplicant is started 2s after wifi driver loaded. It should be
> optimized. The return value is 0 when wifi_load_driver() of Android HAL
> layer is called if wifi driver loaded successfully. And also the property
> value of "wlan.driver.status" is "ok" after wifi driver loaded. It can be
> the way of checking wifi driver is loaded or not.
The wifi driver postpone timer is a workaround started at otoro. I am glad to remove it. 
However, I found a connect to wpa_supplicant permission problem when I removed the 2s timer. 
I checked "wlan.driver.status" is "ok" before starting wpa_supplicant. Any comments is really 
appreciative.

Comment 10

[Vincent Chang[:vchang][changyihsin]]

(In reply to Blake Kaplan (:mrbkap) from comment #6)
> Comment on attachment 782518 [details] [diff] [review]
> Patch v1.0 for mc
> 
> Review of attachment 782518 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I'm fine with this but with one major comment addressed, please avoid
> copy/pasting code. Another place to look for speedups is the wait after we
> load the driver -- we might be able to reduce the amount of time we wait
> (or, even better, find some way for the driver to notify us when it's
> actually fully loaded).

I tried to check "wlan.driver.status". But I found a "connect to wpa_supplicant" problem sometimes.  
 
> ::: dom/wifi/WifiWorker.js
> @@ +708,1 @@
> >    function stopDhcp(ifname, callback) {
> 
> This function basically copy/pastes killSupplicant. Can you factor out the
> common logic (which is everything except one property name and one property
> value)?

I'll post a new patch soon.

Comment 11

[zhangbaisheng]

What's reason of the "connect to wpa_supplicant" problem? As in andorid, uploayer will try again 1s after the last time connecting to wpa_supplicant failed and will try total 5 times when turning on wifi. Please try again when the "connect to wpa_supplicant" problem found, or changed the 2s timer to 1s timer and so on.

Comment 12

[Vincent Chang[:vchang][changyihsin]]

(In reply to zhangbaisheng from comment #11)
> What's reason of the "connect to wpa_supplicant" problem? As in andorid,
> uploayer will try again 1s after the last time connecting to wpa_supplicant
> failed and will try total 5 times when turning on wifi. Please try again
> when the "connect to wpa_supplicant" problem found, or changed the 2s timer
> to 1s timer and so on.

I don't have exactly log on hand. But the problem is related to the permission of /data/misc/wifi/wpa_supplicant/ while connecting to wpa_supplicant. We already have a connection retry timer to reconnect wpa_supplicant.

Comment 13

[Vincent Chang[:vchang][changyihsin]]

This is the log I found if I remove the 2s timer even if the driver status is "ok". 
E/WifiHW  (  884): Unable to open connection to supplicant on "/data/system/wpa_supplicant/": Connection refused

Comment 14

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch v1.1 for mc

I have verified this patch on unagi. It improves the wifi enable time a lot. 
But I am afraid of side effects in other phones. 
1. I check the driver status and only start 2s timer when its status is not "ok".
2. I remove prepareForStartup() when turning on wifi.

Comment 15

[Scoobidiver (away)]

leo+ requested per bug 899451.

Comment 16

[Blake Kaplan (:mrbkap) (inactive)]

(In reply to Vincent Chang[:vchang] from comment #14)
> 2. I remove prepareForStartup() when turning on wifi.

Hi Vincent,

With this change, what happens when the parent dies when we're already connected to a wifi network? Do we successfully reconnect when the process restarts? That is, if you:
* Start the phone.
* Connect to a wifi network.
* Run |adb shell stop b2g; adb shell start b2g|

What happens when b2g comes back?

Also, what was the problem that you mentioned in comment 13? Is it solved?

(In reply to zhangbaisheng from comment #7)
> we have checked that there are two issues which slow down the wifi turn on
> produce: 
> 1. The uplayer loads wifi driver too late after toggling the wifi checkbox
> on. It's about 8s from toggling the wifi checkbox on to loading the wifi
> driver. And do you mean it's the stopDhcp() function problem? I think
> stopDhcp()should be called when turning wifi off. It should not be the
> reason of slowing down the wifi turn on preduce.

The reason that we do this is to recover from crashes. We can't assume that the parent process shut down gracefully, correctly terminating all of the processes, etc.

Comment 17

[Blake Kaplan (:mrbkap) (inactive)]

Comment on attachment 784925 [details] [diff] [review]
Patch v1.1 for mc

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

Before I stamp this, I'd like an answer to my question in comment 16.

::: dom/wifi/WifiWorker.js
@@ -1222,5 @@
> -        Services.obs.notifyObservers(WifiNetworkInterface,
> -                                     kNetworkInterfaceStateChangedTopic,
> -                                     null);
> -
> -        prepareForStartup(function() {

If we do this, then the prepareForStartup function can go away entirely.

@@ +1271,5 @@
> +            // the supplicant to give it a chance to start.
> +            if (status === "ok") {
> +              doStartSupplicant();
> +            }
> +            else {

Nit: The else should cuddle with the previous brace:

  } else {

Comment 18

[Vincent Chang[:vchang][changyihsin]]

(In reply to Blake Kaplan (:mrbkap) from comment #16)
> (In reply to Vincent Chang[:vchang] from comment #14)
> > 2. I remove prepareForStartup() when turning on wifi.
> 
> Hi Vincent,
> 
> With this change, what happens when the parent dies when we're already
> connected to a wifi network? Do we successfully reconnect when the process
> restarts? That is, if you:
> * Start the phone.
> * Connect to a wifi network.
> * Run |adb shell stop b2g; adb shell start b2g|
> 
> What happens when b2g comes back?

Thanks for your reminding. In this case, maybe we can check the property of  init.svc.wpa_supplicant and init.svc.dhcpcd_wlan0 before calling connectionDrop ?  
 
> Also, what was the problem that you mentioned in comment 13? Is it solved?

When I remove the wait driver timer, I found "Unable to open connection to supplicant" message. 
http://androidxref.com/4.0.4/xref/hardware/libhardware_legacy/wifi/wifi.c#601 

It seems to me that wpa_supplicant is not ready to go even if the loadDriver and start_supplicant callbacks indicate us so.
For the unagi, wpa_supplicant set the wifi.wpa_supp_ready property to indicate that it is running. The wifi worker thread who calls wifi_start_supplicant waiting  
there until wifi.wpa_supp_ready is "1". Not sure if any is something wrong here. 
Let me check it in more detail to see if I can find the root cause.

Comment 19

[Blake Kaplan (:mrbkap) (inactive)]

(In reply to Vincent Chang[:vchang] from comment #18)
> Thanks for your reminding. In this case, maybe we can check the property of 
> init.svc.wpa_supplicant and init.svc.dhcpcd_wlan0 before calling
> connectionDrop ?

That seems reasonable.

> Let me check it in more detail to see if I can find the root cause.

Sounds good.

Comment 20

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch for mc v1.2

It's very hard to reproduce the problem when I remove the driver wait timer. However, the Wifi did broken sometimes if I remove that timer. So I decide to let partner be a decision maker and leave a option in ro.moz.wifi.driverDelay property. The default value is 2 seconds. With this patch, the Wifi startup time is improved to about 7 seconds from turning on to connect to AP in most of time. If we can get rid of the driver wait timer, the Wifi startup time can decrease to about 3 seconds.

Comment 21

[Blake Kaplan (:mrbkap) (inactive)]

Comment on attachment 789472 [details] [diff] [review]
Patch for mc v1.2

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

This seems like a reasonable solution.

Slightly related to this bug, please file a followup about getting rid of getProperty and using get_property directly (without going through the control worker). We did it on the worker originally to prevent jank, but apparently that's not a concern. It's even possible that doing this might help startup time a little as it'll reduce the number of messages we send to the control worker and have to wait for the response. At the very least, it'll make some code much prettier.

Comment 22

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch for b2g18 v1.2

Update the patch to use libcutils.property_get directly.

Comment 23

[Vincent Chang[:vchang][changyihsin]]

This patch is verified on buri using b2g18 and gaia v1-train.

Comment 24

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch for mc v1.3

Update the patch to use libcutils.property_get directly to address the review comment. This patch is verified on unagi.

Comment 25

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch rebase v1.4 for mc

Rebase the patch.

Comment 26

[Vincent Chang[:vchang][changyihsin]]

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

Comment 27

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch ready to commit for b2g18 v1.3

Remove the trail space.

Comment 28

[Ed Morley [:emorley]]

Backed out for Marionette failures:
https://tbpl.mozilla.org/php/getParsedLog.php?id=26626136&tree=B2g-Inbound
https://tbpl.mozilla.org/php/getParsedLog.php?id=26625112&tree=B2g-Inbound


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

Comment 29

[Ed Morley [:emorley]]

Also mochitest-3 failures:
https://tbpl.mozilla.org/php/getParsedLog.php?id=26625782&tree=B2g-Inbound

Comment 30

[Vincent Chang[:vchang][changyihsin]]

push to try server.
https://tbpl.mozilla.org/?tree=Try&rev=5b25db89678e

Comment 31

[Vincent Chang[:vchang][changyihsin]]

Attachment: Patch v1.5 for mc

Fixed the marionette test fails.

Comment 32

[Vincent Chang[:vchang][changyihsin]]

push to try for v1.5 in the attached file.

https://tbpl.mozilla.org/?tree=Try&rev=e3e0d658a3c2

Comment 33

[Vincent Chang[:vchang][changyihsin]]

push to inbound. 
https://hg.mozilla.org/integration/b2g-inbound/rev/1562233fed4d

Comment 34

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/1562233fed4d

Comment 35

[Ryan VanderMeulen [:RyanVM]]

Needs a branch-specific patch for uplift.

Comment 36

[Alex Keybl [:akeybl]]

This is definitely not leo+, since this is not a regression.

Comment 37

[Vincent Chang[:vchang][changyihsin]]

Since it's not a leo+ now, I'll not provide a patch for b2g18.