879343 - [B2G][Leo][Unagi][Inbound Calls]User Cannot receive inbound calls

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::Dialer, defect)

Description

[Sarah Parsons]

Attachment: Unagi v1.1 logcat

Description:
The user will be unable to receive calls. The screen will light up when the device is called but no notification of a call coming in happens.

Repro Steps:
1) Updated to Buri Build ID: 20130604070205
2) On separate device, make a call to the phone.

Actual:
Screen will light up as if were about to start ringing but no call comes in.

Expected:
Phone should ring and the user should be notified that someone is calling them.

Environmental  Variables:
Kernel Date: Mar 15
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/997cdbf5d012
Gaia: 5534304aee934055f08f21ce93261ba2a596516a

Notes:
Repro frequency: 100%

This issue also occurs on the Unagi device Build ID: 20130604070205

Attached is the logcat for the Unagi.

Comment 1

[Allen Maxwell]

Needs escalation to Pr i 1. Affects smoketest outcome.

Comment 2

[Allen Maxwell]

per comment 1; please escalate to Pri 1

Comment 3

[Tony Chung [:tchung]]

Dylan, can you find a developer to investigate this?  This is a smoketest blocker and a regression from yesterday's build.  Thanks

Comment 4

[Allen Maxwell]

As in comment 0, this issue is occurring on both the Unagi and Buri. 
-It affects inbound calls only.
-Devices do see SIM card.

Comment 5

[Marcia Knous [:marcia]]

Using:

Gecko  http://hg.mozilla.org/releases/mozilla-b2g18/rev/997cdbf5d012
Gaia   5534304aee934055f08f21ce93261ba2a596516a
BuildID 20130604070205
Version 18.0

I have been able to get some inbound calls on the Unagi device, but not every time.

Comment 6

[Marcia Knous [:marcia]]

If I reboot the Unagi device, it seems as if the first incoming call rings fine. After that the phone doesn't seem to receive the inbound call. Using an AT&T card.

Comment 7

[Marcia Knous [:marcia]]

I forgot to mention that my screen did not light up as if an incoming call was coming in. I am flashing another Unagi to compare results.

Comment 8

[Sarah Parsons]

We were able to reproduce the issue in comment6 on both the Unagi and the Buri.

Restarting the phone will allow 1 call to come through, but after that no calls can be received.

Comment 9

[Michael Wu [:mwu]]

I can't reproduce reliably on Leo. Sometimes a call gets missed, but the call after goes through. The signal isn't great where I am.

Comment 10

[Walter Chen[:ypwalter][:wachen]]

I can reproduce in unagi v1train - 20130604135937.

Comment 11

[Walter Chen[:ypwalter][:wachen]]

1. You need to pick up the first phone call
2. If you turn off the screen(lock), it might be okay to pick up the phone
3. If you keep your screen on, you will not be able to even see the notification.

Comment 12

[Gregor Wagner [:gwagner]]

There is something bad going on:
E/GeckoConsole(  422): [JavaScript Error: "[Exception... "Component returned failure code: 0x80570009 (NS_ERROR_XPC_BAD_CONVERT_JS) [nsIXPCComponents_Utils.createObjectIn]"  nsresult: "0x80570009 (NS_ERROR_XPC_BAD_CONVERT_JS)"  location: "JS frame :: resource://gre/modules/ObjectWrapper.jsm :: objWrapper_wrap :: line 56"  data: no]" {file: "resource://gre/modules/ObjectWrapper.jsm" line: 56}]

Comment 13

[Gregor Wagner [:gwagner]]

We notice the call, start some settings-requests and destroy the inner-windows. Seems like the oncall screen gets killed before we even show it:

06-05 09:04:49.249 I/Gecko   ( 1924): -*- SettingsManager: get for: phone.ring.keypad
06-05 09:04:49.249 I/Gecko   ( 1924): -*- SettingsManager: get for: audio.volume.notification
06-05 09:04:49.259 I/Gecko   ( 1924): -*- SettingsManager: get for: dialer.ringtone
06-05 09:04:49.259 I/Gecko   ( 1924): -*- SettingsManager: get for: vibration.enabled
06-05 09:04:49.309 I/Gecko   ( 1924): -*- SettingsManager: Topic: inner-window-destroyed
06-05 09:04:49.319 I/Gecko   ( 1924): -*- SettingsManager: Topic: inner-window-destroyed
06-05 09:04:49.319 I/Gecko   ( 1924): -*- SettingsManager: Topic: inner-window-destroyed

Comment 14

[Gregor Wagner [:gwagner]]

We should try to get a better idea when this started.

Comment 15

[Shian-Yow Wu [:swu]]

Attachment: RIL log (Moz RIL)

This log contains one successful and one failure call(see line 913~), reproduce by Unagi phone with v1-train + mozilla-b2g18.

Comment 16

[Hsin-Yi Tsai (she/her)[:hsinyi]]

I think this issue results from bug 823958, which changes Telephony WebAPI behaviour a little bit. Now bug 823958 guarantees that app will get the event 'callschanged' once the calls array is valid, even if it is empty. That helps automatically resolve some edge cases of call screen transition. But we will need corresponding modification in gaia to make sure the behaviour of those event handlers fit the new API. 

What's happening here is:
When dialer.js receives system message 'telephony-new-call,' it opens call screen. Note that at that moment the RIL call object may not be ready since we open call screen earlier before we get complete call information [1]. 

Then in [2], a new window initiates to mozTelephony. Later, [3] is called when the 'empty' calls array is loaded. So it jumps in [4] and call screen is closed. And we have no chance to open the screen again even after the ril call gets ready.

[1] https://mxr.mozilla.org/mozilla-central/source/dom/system/gonk/ril_worker.js#5405
[2] https://github.com/mozilla-b2g/gaia/blob/v1-train/apps/communications/dialer/js/oncall.js#L184
[3] https://github.com/mozilla-b2g/gaia/blob/v1-train/apps/communications/dialer/js/oncall.js#L259
[4] https://github.com/mozilla-b2g/gaia/blob/v1-train/apps/communications/dialer/js/oncall.js#L294

Comment 17

[Hsin-Yi Tsai (she/her)[:hsinyi]]

Attachment: gaia - adding debug messages

I added some debug messages in dialer.js and oncall.js to help clarify my comment #16.

=== Expected sequence === 
06-05 21:38:06.577 I/GeckoDump( 1177): XXX dialer - newCall
06-05 21:38:06.577 I/GeckoDump( 1177): XXX dialer - openCallScreen
06-05 21:38:07.228 I/GeckoDump( 1177): XXX dialer - callScreenWindow: [object Window]
06-05 21:38:07.368 I/GeckoDump( 1177): XXX dialer = oncallschanged: 1
06-05 21:38:07.408 I/GeckoDump( 1177): XXX dialer = oncallschanged: 1
06-05 21:38:07.878 I/GeckoDump( 1177): XXX oncall - onCallsChanged - calls.length: 1
06-05 21:38:07.928 I/GeckoDump( 1177): XXX oncall - onCallsChanged - calls.length: 1
06-05 21:38:08.179 I/GeckoDump( 1177): XXX dialer - callScreenWindow.onload
06-05 21:38:17.287 I/GeckoDump( 1177): XXX dialer = oncallschanged: 0
06-05 21:38:17.287 I/GeckoDump( 1177): XXX dialer - exitCallScreen
06-05 21:38:17.297 I/GeckoDump( 1177): XXX oncall - onCallsChanged - calls.length: 0
06-05 21:38:17.297 I/GeckoDump( 1177): XXX oncall - exitCallScreen

=== Failed sequence ===
06-05 21:38:31.421 I/GeckoDump( 1177): XXX dialer - newCall
06-05 21:38:31.421 I/GeckoDump( 1177): XXX dialer - openCallScreen
06-05 21:38:31.661 I/GeckoDump( 1177): XXX dialer - callScreenWindow: [object Window]
06-05 21:38:31.732 I/GeckoDump( 1177): XXX dialer = oncallschanged: 0
06-05 21:38:32.212 I/GeckoDump( 1177): XXX oncall - onCallsChanged - calls.length: 0
06-05 21:38:32.212 I/GeckoDump( 1177): XXX oncall - exitCallScreen
06-05 21:38:32.392 I/GeckoDump( 1177): XXX dialer - callScreenWindow.onload
06-05 21:38:32.512 I/GeckoDump( 1177): XXX dialer = oncallschanged: 1
06-05 21:38:42.112 I/GeckoDump( 1177): XXX dialer = oncallschanged: 0
06-05 21:38:42.112 I/GeckoDump( 1177): XXX dialer - exitCallScreen

Comment 18

[Hsin-Yi Tsai (she/her)[:hsinyi]]

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #16)
> I think this issue results from bug 823958, which changes Telephony WebAPI
> behaviour a little bit. Now bug 823958 guarantees that app will get the
> event 'callschanged' once the calls array is valid, even if it is empty.
> That helps automatically resolve some edge cases of call screen transition.
> But we will need corresponding modification in gaia to make sure the
> behaviour of those event handlers fit the new API. 

Etienne, does that sound reasonable to you? More comments? Thanks!

Comment 19

[Angela Hubenya]

Regression window results for v1: 
2013-06-03-07-02-07 PASS
2013-06-03-23-02-07 FAIL

Comment 20

[Jason Smith [:jsmith]]

(In reply to Angela Hubenya from comment #19)
> Regression window results for v1: 
> 2013-06-03-07-02-07 PASS
> 2013-06-03-23-02-07 FAIL

I'm going to guess bug 876640 caused this regression.

Comment 21

[Nick Davidson]

This issue also repro on today's Leo 1.1 com. RIL 
Screen will light up as if were about to start ringing showing locked screen but no call comes in

Leo Build ID: 20130605070207
Kernel Date: Apr 25
Gecko: http://hg.mozilla.org/releases/mozilla-b2g18/rev/09dc1ae3b1b5
Gaia: 92a6e36957145cdb2ac8867e5cdba8ecf12308fc

Comment 22

[Hsin-Yi Tsai (she/her)[:hsinyi]]

Attachment: PR to gaia

Due to bug 823958, we will need some modifications in gaia as well. Since bug 823958 guarantees that app will get the event 'callschanged' once the calls array is valid, even if it is empty, we shouldn't let oncall.js handle existing call screen. Otherwise the screen will be unfortunately closed by the first callschanged event. Instead, I propose to let dialer.js take care of both opening and closing call screen. Would you please help review this? Thank you.

Comment 24

[Wayne Chang [:wchang]]

leo+ing for obvious regression/blocker.

Comment 25

[Etienne Segonzac (:etienne)]

Comment on attachment 758934 [details]
PR to gaia

Thank you so much Hsin-Yi!

Sorry this API change was so painful, but really glad to see the dialer code shaping up like this :)

Comment 26

[Etienne Segonzac (:etienne)]

https://github.com/mozilla-b2g/gaia/commit/7fd0d8b8aea352640799b8639d37b28c10842e6f

Comment 27

[Hsin-Yi Tsai (she/her)[:hsinyi]]

(In reply to Etienne Segonzac (:etienne) from comment #25)
> Comment on attachment 758934 [details]
> PR to gaia
> 
> Thank you so much Hsin-Yi!
> 
> Sorry this API change was so painful, but really glad to see the dialer code
> shaping up like this :)

Thanks for merging :)
Yes, it's really nice that we have a solid solution to those call screen edge cases. \0/

Comment 29

[Walter Chen[:ypwalter][:wachen]]

I think there should be test cases to check multiple calls.
This could be calling multiple times, calling from different devices, call outbound&inbound.

Comment 30

[Angela Hubenya]

UCID: owd-1987

Comment 31

[John Ford [:jhford] CET/CEST Berlin Time]

Uplifted 7fd0d8b8aea352640799b8639d37b28c10842e6f to:
v1-train: 03b81469d88d92cf9e968b20cf117052e2d4e7ca

Comment 32

[Walter Chen[:ypwalter][:wachen]]

Angela,
it's different.
if you test by the test you provide, it won't help.
Please refer to comment 11.

You need to call twice in order to see the bug reproduced.
This bug is after 2nd time called, it won't show on the screen.

Comment 33

[Walter Chen[:ypwalter][:wachen]]

Buri or v1.0.1 is not affected.

I hereby verified fixed in unagi pvt v1train 2013/06/09 & unagi pvt master 2013/06/09.

Comment 34

[John Hammink]

Verified fixed on 6/10 leo frankenbuild:

Gecko  http://hg.mozilla.org/releases/mozilla-b2g18/rev/8e3f39363c54
Gaia   ce3b99781d182ad550a325206990c249b0dbcf0e
BuildID 20130610070206
Version 18.0

Comment 35

[Angela Hubenya]

Walter, 
I have created another test case that fits this bug more. Let me know if I missed something.