1062550 - b2g crashes during USB tethering

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Wifi, defect, P1)

Description

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

STR:

1) Run random stability test with USB tethering enabled:

Logs : 

https://drive.google.com/file/d/0B1cSMS8_GuAEUF9zSWdLTGlyV3c/edit?usp=sharing

Comment 1

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

[Blocking Requested - why for this release]:

Comment 2

[cafbot (PoC: ggrisco)]

Observed on: 

Device: msm8226
Gonk Version: AU_LINUX_GECKO_B2G_KK_3.6.01.04.00.000.074
Moz BuildID: 20140826000204
B2G Version: 2.0
Gecko Version: 32.0
Gaia:  http://git.mozilla.org/?p=releases/gaia.git;a=commit;h=a51633e29a7826b6bf07cb1c5ad81b3217b9820a
Gecko: http://git.mozilla.org/?p=releases/gecko.git;a=commit;h=8f121f8fa5fa1a3e82967f91e2afe337465fc593

Comment 3

[Michael Vines [:m1] [:evilmachines]]

Please attach the minidump.  Maybe a dup of bug 1062548 looking at the dump over here though.  Both have 
libxul.so!NetworkUtils::setUSBTethering(NetworkParams&)  [NetworkUtils.cpp : 1611 + 0x13] on the stack

Comment 4

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: 20686bba-bb91-5eb6-36d7b122-2d1974fc.txt

(In reply to Michael Vines [:m1] [:evilmachines] from comment #3)
> Please attach the minidump.  Maybe a dup of bug 1062548 looking at the dump
> over here though.  Both have 
> libxul.so!NetworkUtils::setUSBTethering(NetworkParams&)  [NetworkUtils.cpp :
> 1611 + 0x13] on the stack

here is the decoded minidump from logs in Comment 0.

Comment 5

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: 20686bba-bb91-5eb6-36d7b122-2d1974fc.extra

.extra file from logs in Comment 0. Please note that link in Comment 0 also has full logcat logs when this issue happens.

Comment 6

[Inder]

Bhavana -- can you please get someone to look into it asap. It's affecting out stability and high priority issue.

Comment 7

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

I'm going to give this one to Henry since he owns bug 1061993.  He can figure out if he's the right owner when he wakes up.

Comment 8

[bhavana bajaj [:bajaj]]

Inder, we'll have to wait for Taipei to wake up to  move here, I'll get in touch with them.

Comment 9

[Henry Chang [:hchang]]

It doesn't seem to be the dupe of Bug 1061993 at first glance.
Will update here when I've done the preliminary investigation.
Thanks.

Comment 10

[Henry Chang [:hchang]]

According to attachment 8483947 [details], the process which kept crashing was dnsmasq.
Is it the right log? Also, is the usb tethering function totally broken?
Or it just crashes from time to time?

Comment 11

[Henry Chang [:hchang]]

I am wondering if the crashing of dnsmasq causes netd to return 
abnormal value and in turn NetworkUtils.cpp doesn't handle the
error case well. Is the debug flag able to open to gather more
information in the adb log?

[1] http://git.mozilla.org/?p=releases/gecko.git;a=blob;f=dom/system/gonk/NetworkUtils.cpp;h=59534d31735b0390fc1351d50a6f1a8eed3c4a24;hb=8f121f8fa5fa1a3e82967f91e2afe337465fc593#l28

Comment 12

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Attachment: more logs by enabling debug flag in gaia/gecko/dnsmasq

I debugged this issue further on our device by enabling additional logs .

setUSBTethering JS functtion is called with 'true' twice consecutively which is breaking setdnmasq binary and causing b2g process to crash

Could you please make sure that setUSBTethering JS functtion is called only once if USB tethering already set ?

Comment 13

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Could you please give me quick fix for my comment in Comment 12 ? I think that this will solve this issue.

Comment 15

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

@henry:

One more hints : If you try to find out why we are seeing this line 

09-05 00:08:18.456   194   742 D TetherController CAFLOG: Sending update msg to dnsmasq [update_ifaces:rndis0:rndis0] 

in logs of comment 12 then you will understand why we should not call setUSBTethering JS function again when USB tethering is already set.

Comment 16

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Hi henry, I don't see you in #gaia/#b2g IRC. Could you please let me know your IRC channel name so that we can discuss and get a quick fix for this bug ?

Comment 17

[Henry Chang [:hchang]]

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #12)
> Created attachment 8484849 [details]
> more logs by enabling debug flag in gaia/gecko/dnsmasq
> 
> I debugged this issue further on our device by enabling additional logs .
> 
> setUSBTethering JS functtion is called with 'true' twice consecutively which
> is breaking setdnmasq binary and causing b2g process to crash
                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  Did you also find why?  
> 
> Could you please make sure that setUSBTethering JS functtion is called only
> once if USB tethering already set ?

I need some time to deal with this. I could take a quick look
and update here before leaving. Thanks.

Comment 18

[Henry Chang [:hchang]]

(In reply to Henry Chang [:henry] from comment #17)
> (In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from
> comment #12)
> > Created attachment 8484849 [details]
> > more logs by enabling debug flag in gaia/gecko/dnsmasq
> > 
> > I debugged this issue further on our device by enabling additional logs .
> > 
> > setUSBTethering JS functtion is called with 'true' twice consecutively which
> > is breaking setdnmasq binary and causing b2g process to crash
>                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>   Did you also find why?  

I guess it's due to NetworkUtils.cpp maintains only one command
chain so if one request is received before the previous one finishes,
something would be messed up.

> > 
> > Could you please make sure that setUSBTethering JS functtion is called only
> > once if USB tethering already set ?
> 
> I need some time to deal with this. I could take a quick look
> and update here before leaving. Thanks.

Comment 19

[Henry Chang [:hchang]]

Attachment: Bug1062550.patch

I found quickly toggling the usb tethering settings may screw 
up the internal state. In particular, the callback function [1]
references the state variable which might be different from
the request. Bind the action(enable or disable) to the callback
to mitigate this issue. I haven't gone through all the possible 
transition. If this bug is easily to reproduce it's worthy of 
trying this patch out.

I'll continue to dig deeper next week. Thanks.

[1] http://hg.mozilla.org/releases/mozilla-b2g32_v2_0/file/2fae20afe1fa/dom/system/gonk/NetworkManager.js#l1119

Comment 20

[cafbot (PoC: ggrisco)]

Observed on: 

Device: msm8226
Gonk Version: AU_LINUX_GECKO_B2G_KK_3.6.01.04.00.000.080
Moz BuildID: 20140903000206
B2G Version: 2.0
Gecko Version: 32.0
Gaia:  http://git.mozilla.org/?p=releases/gaia.git;a=commit;h=449d8db9b3ea1f9262db822c37ef2143477172b7
Gecko: http://git.mozilla.org/?p=releases/gecko.git;a=commit;h=be914f092bb7916e1c5f33fc94aa4217cd375b65

Comment 21

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

Comment on attachment 8484904 [details] [diff] [review]
Bug1062550.patch

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

I added following change on top of your patch : 

52	+         (this._usbTetheringAction === TETHERING_STATE_ONGOING ||
		53	+          this._usbTetheringAction === TETHERING_STATE_ACTIVE)) {
		54	+       debug("Usb tethering already connecting/connected.");
		55	++      if(this._requestCount > 0) {
		56	++        this._requestCount--;
		57	++        debug("handleUSBTetheringToggle this._requestCount "+this._requestCount);
		58	++      }
		59	+       return;
		60	+     }
		61	+ 
		62	+     if (!enable &&
		63	+         this._usbTetheringAction === TETHERING_STATE_IDLE) {
		64	+       debug("Usb tethering already disconnected.");
		65	++      if(this._requestCount > 0) {
		66	++        this._requestCount--;
		67	++        debug("handleUSBTetheringToggle this._requestCount "+this._requestCount);
		68	++      }

Then it worked for me :) .

I would suggest you to do these changes and review it again before landing. Thanks for quick help :)

Comment 22

[Henry Chang [:hchang]]

Hi Tapas,

I don't think we need to decrease |this._requestCount|.
Have you verified (actual auto test) the change you made 
on top of mine is necessary?

Thanks!

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #21)
> Comment on attachment 8484904 [details] [diff] [review]
> Bug1062550.patch
> 
> Review of attachment 8484904 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I added following change on top of your patch : 
> 
> 52	+         (this._usbTetheringAction === TETHERING_STATE_ONGOING ||
> 		53	+          this._usbTetheringAction === TETHERING_STATE_ACTIVE)) {
> 		54	+       debug("Usb tethering already connecting/connected.");
> 		55	++      if(this._requestCount > 0) {
> 		56	++        this._requestCount--;
> 		57	++        debug("handleUSBTetheringToggle this._requestCount
> "+this._requestCount);
> 		58	++      }
> 		59	+       return;
> 		60	+     }
> 		61	+ 
> 		62	+     if (!enable &&
> 		63	+         this._usbTetheringAction === TETHERING_STATE_IDLE) {
> 		64	+       debug("Usb tethering already disconnected.");
> 		65	++      if(this._requestCount > 0) {
> 		66	++        this._requestCount--;
> 		67	++        debug("handleUSBTetheringToggle this._requestCount
> "+this._requestCount);
> 		68	++      }
> 
> Then it worked for me :) .
> 
> I would suggest you to do these changes and review it again before landing.
> Thanks for quick help :)

Comment 23

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

(In reply to Henry Chang [:henry] from comment #22)
> Hi Tapas,
> 
> I don't think we need to decrease |this._requestCount|.
> Have you verified (actual auto test) the change you made 
> on top of mine is necessary?


yes, I verified by rapid firing usb tethering button on/off in settings. I hit same crash if I don't apply my change on top of your change. Thanks for good work

Comment 24

[Henry Chang [:hchang]]

Cool! I will also have it a try tmr and proceed in review/landing 
the patch. Thanks!

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #23)
> (In reply to Henry Chang [:henry] from comment #22)
> > Hi Tapas,
> > 
> > I don't think we need to decrease |this._requestCount|.
> > Have you verified (actual auto test) the change you made 
> > on top of mine is necessary?
> 
> 
> yes, I verified by rapid firing usb tethering button on/off in settings. I
> hit same crash if I don't apply my change on top of your change. Thanks for
> good work

Comment 25

[Henry Chang [:hchang]]

Attachment: Patch V2 (For 2.0/2.1/master)

Comment 26

[Henry Chang [:hchang]]

(In reply to Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me) from comment #23)
> (In reply to Henry Chang [:henry] from comment #22)
> > Hi Tapas,
> > 
> > I don't think we need to decrease |this._requestCount|.
> > Have you verified (actual auto test) the change you made 
> > on top of mine is necessary?
> 
> 
> yes, I verified by rapid firing usb tethering button on/off in settings. I
> hit same crash if I don't apply my change on top of your change. Thanks for
> good work

I still cannot hit the crash without your change but I've
already realized it's necessary. Besides, another change 
also needs to be made to avoid interleaving usb tethering
enable/disable chain.

Attached the final patch for review which includes three
changes.

Comment 27

[Henry Chang [:hchang]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

Hi Vincent,

I flagged you for reviewing first since you are the 
original author of usb tethering. This patch makes 3 
significant changes regarding rapidly toggling usb tethering:

1) Bind the action (enable/disable) to the callback function
   |usbTetheringResultReport|.

2) Set |this._requestCount| to 1 instead of 0 to prevent
   from the subsequent settings change triggering another
   |handleUSBTetheringToggle| before the previous one finishes.

3) Reset |this._requestCount| to 0 whenever the request 
   doesn't take effect.

Thanks!

Comment 28

[Vincent Chang[:vchang][changyihsin]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

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

Looks good. Thank you.

Comment 29

[Henry Chang [:hchang]]

Hi Tapas, 

Given the r+'d patch, do you want to include the patch to have
an final automation test before landing? 

Thanks!

Comment 30

[Tapas[:tkundu on #b2g/gaia/memshrink/gfx] (always NI me)]

(In reply to Henry Chang [:henry] from comment #29)
> Hi Tapas, 
> 
> Given the r+'d patch, do you want to include the patch to have
> an final automation test before landing? 
> 
> Thanks!

Patch looks fine to me :)

Comment 31

[howie [:howie]]

Hi Henry, please land this, thanks.

Comment 32

[Henry Chang [:hchang]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
[Bug caused by] (feature/regressing bug #): USB tethering
[User impact] if declined: Rapidly switch USB tethering on and off will cause b2g crashing
[Testing completed]: Yest
[Risk to taking this patch] (and alternatives if risky): No
[String changes made]: No

Comment 33

[bhavana bajaj [:bajaj]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

Switching back the approval as this needs to land on master and get FIXED first. Also does this patch apply to 2.1?

Comment 34

[howie [:howie]]

Hi Henry, Gecko patch is to request approval flag: approval‑mozilla‑b2g32 (v2.0). If the patch also apply to v2.1, please request the following approval too: approval‑mozilla‑aurora.

Comment 35

[Henry Chang [:hchang]]

Oops I flagged wrong one... sorry for that.

Comment 36

[Henry Chang [:hchang]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

NOTE: Please see https://wiki.mozilla.org/Release_Management/B2G_Landing to better understand the B2G approval process and landings.

[Approval Request Comment]
Bug caused by (feature/regressing bug #): USB tethering 
User impact if declined: Rapidly switching usb tethering on and off will cause b2g crash. 
Testing completed: Yes
Risk to taking this patch (and alternatives if risky): No  
String or UUID changes made by this patch: No

Comment 37

[Henry Chang [:hchang]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

Approval Request Comment
[Feature/regressing bug #]: USB tethering
[User impact if declined]: Rapidly switch USB tethering on/off will cause b2g to crash
[Describe test coverage new/current, TBPL]:
[Risks and why]: No risk.
[String/UUID change made/needed]: No

Comment 38

[Vincent Chang[:vchang][changyihsin]]

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

Comment 39

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 8486964 [details] [diff] [review]
Patch V2 (For 2.0/2.1/master)

b2g30 is v1.4, so I'm assuming that changing the nom from b2g32 was in error.

Comment 40

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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

Comment 41

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/e40762374799
https://hg.mozilla.org/releases/mozilla-b2g32_v2_0/rev/f42069d18e3e

Please note for the future that in general, your commit message should be summarizing what the patch is actually doing, not restating the problem it's trying to solve :)
https://developer.mozilla.org/en-US/docs/Developer_Guide/Committing_Rules_and_Responsibilities#Checkin_comment

Comment 42

[Kai-Zhen Li [:seinlin][:kli]]

http://hg.mozilla.org/releases/mozilla-b2g32_v2_0m/rev/f42069d18e3e

Comment 43

[Tony Chung [:tchung]]

Verifyme to check if this is fixed on 2.1

Comment 44

[Brogan Zumwalt [Inactive]]

Cannot verify on bug due to automation steps as we cannot run these tests at our location.

Comment 45

[Parul Mathur [:pragmatic] - out of office - please ni? [:bajaj] instead]

Verified fixed on Flame device running b2g v2.1

Test Environment
Device: Flame
Base image: v188
Gaia: c97463d61f45513a2123b19610386ddbfc916819
Gecko: 4f8c0c021128
Build-ID: 20141027001201
Platform Version: 34.0
OS Version: 2.1.0.0-prerelease
Update Channel: nightly-b2g34
Git Commit Info: 2014-10-24 21:57:55

Steps to reproduce:
1. Connect the phone to the Internet via WiFi or cellular data connection.
2. Connect the phone to a computer via a USB cable.
3. On the phone, go to Settings > Internet Sharing.
4. Tap rapidly on the USB tethering checkbox to turn it on and off successively.   

Expected Results:
The phone remains stable and does not crash.

Actual Results:
The phone remains stable and does not crash.

Comment 46

[Coler]

Verify passed, this issue can't be repro on Woodduck 2.0;Flame2.0&2.2
Attached: Verify_Woodduck_USB.mp4
Reproducing rate: 0/5

Woodduck build:
Gaia-Rev        cc690f8016b672475dc186bc7fd58aef45e684b7
Gecko-Rev       03d3ab62d5b07b915434f2d1d68495ad5915ecd2
Build-ID        20141118184148
Version         32.0

Flame2.0 build:
Gaia-Rev        1ede2666f1e6c1b3fd3b282011caf0cbc59544b0
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g32_v2_0/rev/faa64077b0c2
Build-ID        20141119000207
Version         32.0

FLame2.2 build:
Gaia-Rev        e64428c5b2dce5db90b75a5055077a04f4bd4819
Gecko-Rev       https://hg.mozilla.org/mozilla-central/rev/aa72ddfe9f93
Build-ID        20141119160202
Version         36.0a1

Comment 47

[Coler]

Attachment: Verify_Woodduck_USB.MP4