1002838 - [B2G][Tarako][Dialer]Manually dialing voicemail in a three way call freezes the phone

Status: RESOLVED DUPLICATE of bug 1007598

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

Description

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Attachment: logcat_20140428_1630_multi_recipient_self_call.txt

Description:
If the user calls voicemail by manually dialing it during another call (three way call), the phone will freeze.  The other device will remain on the line as long as they don't hang up.  No crash log is created.

Repro Steps:
1) Update a Tarako to BuildID: 20140428014001
2) Open the Dialer and call another device
3) Wait for the call to connect
4) Call voicemail by manually dialing the number.

Actual:
The device freezes as soon as the second call begins.

Expected:
The phone connects to voicemail naturally.

1.3T Environmental Variables:
Device: Tarako 1.3T MOZ
BuildID: 20140428014001
Gaia: 8895b180ed636069473703d0e7b73086989601ce
Gecko: 7caf4b5abfce
Version: 28.1
Firmware Version: sp6821

Repro frequency: 100%
See attached: logcat, firewatch report, video

Comment 1

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

This issue does not occur on 1.3 Buri

1.3 Environmental Variables:
Device: Buri 1.3 MOZ
BuildID: 20140425024003
Gaia: 32a9e3db738e0b3bc44a4d4d5c16512a2617a2cf
Gecko: c96b0cf6343f
Version: 28.0
Firmware Version: v1.2-device.cfg

The call reaches their voicemail as expected.

Comment 2

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Attachment: firewatch_20140428_1630_multi_recipient_self_call.txt

Comment 3

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Jayme, when you say freeze, do you mean you have to pull the battery out?

Comment 4

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Yes the battery must be removed to use the phone again.

I have also made the video you can see here.

http://youtu.be/MggeGFM6hXQ

Comment 5

[Joe Cheng [:jcheng] (please needinfo)]

ni? Sku

triage: 1.3T+ for a hang issue

Comment 6

[shawn ku [:sku]]

Hi Jayme:
 I cannot repo. this issue at my side.
And it seems ril related log is off.

// Log analysis
/*
 * 3 MO calls were made? but only one disconnect????
 */
04-28 16:25:04.242   477   477 I log     : <4>0[ 98.984995] lowmem_shrink select 411 (Communications), adj 10, size 8183, to kill
04-28 16:26:06.792   598   598 I log     : <4>0[ 161.551422] lowmem_shrink select 530 (Usage), adj 10, size 5371, to kill
04-28 16:28:34.832   640   640 I log     : <4>0[ 309.567081] lowmem_shrink select 481 (Communications), adj 10, size 6393, to kill
04-28 16:30:12.732    83   291 I Gecko   : RIL Worker: [0] Create a pending outgoing call.
04-28 16:30:14.042   701   701 I log     : <4>0[ 408.820813] lowmem_shrink select 605 (Settings), adj 10, size 6690, to kill
04-28 16:30:44.292    83   291 I Gecko   : RIL Worker: [0] Create a pending outgoing call.
04-28 16:30:54.482   803   803 I log     : <4>0[ 449.220228] lowmem_shrink select 637 (Communications), adj 10, size 7505, to kill
04-28 16:31:13.142    83   291 I Gecko   : RIL Worker: [0] Create a pending outgoing call.
04-28 16:31:13.162    83   291 I Gecko   : RIL Worker: [0] Disconnect pending outgoing call
04-28 16:31:14.872   919   919 I log     : <4>0[ 469.669997] lowmem_shrink select 846 ((Preallocated a), adj 10, size 4642, to kill




Could you please follow below steps to enable ril log, and try to get log again?

// Enable ril STRs
1 adb pull /system/b2g/defaults/pref/user.js /tmp
2 Modify /tmp/user.js, and set the value of ril.debugging.enabled to true.
      pref("ril.debugging.enabled", true);
3 adb remount
4 adb push /tmp/user.js /system/b2g/defaults/pref/
5 adb reboot

// Log command
adb logcat -b radio -b main -v threadtime > /tmp/1002838.log

Comment 7

[shawn ku [:sku]]

BTW, my version:
Gaia      b5adc5a943d3abbd6ab070a47c847f2c24891cc5
Gecko     8a7c8b72625666950a09cfcfa5d6c953dd7d27b6
BuildID   20140429180512
Version   28.1
ro.build.version.incremental=eng.sku.20140429.180455
ro.build.date=Tue Apr 29 18:05:00 CST 2014

Comment 8

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Attachment: 1002838.log

I'm attaching the log as requested.  I was not sure if the name you chose in your command was a desired name or not so I left it as is.  

Of note:  After turning on RIL debugging, the repro rate for this issue seems to have dropped.  It took me 2-4 three-way calls to the voicemail per repro instead of on the first every time.

Comment 9

[shawn ku [:sku]]

From ril's perspective

User tried to place a new call to 6509605939 around 04-29 09:47:48.931.
And that call cannot be made. (rejected immediately after dial), gecko report callDisconnected event too.

Might need system/gaia team to check further what cause hang (see comment 4).
BTW, I still can not repro this issue on my side.


// Log snippet
04-29 09:47:32.641  1182  1182 I log     : <4>0[ 652.548712] lowmem_shrink select 1041 (Communications), adj 10, size 7688, to kill

04-29 09:47:32.671    96   318 D RILC    : [0519]< GET_CURRENT_CALLS {[id=1,ACTIVE,toa=129,norm,mo,als=0,voc,noevp,7012406542,cli=0,name='(null)',0}
04-29 09:47:48.931    96   318 D RILC    : [0531]> DIAL (num=6509605939,clir=0)
04-29 09:47:48.941    96   209 D RIL     : The last call fail cause: 34
04-29 09:47:48.941    96   318 D RILC    : [0531]< DIAL
04-29 09:47:48.971    96   318 D RILC    : [0534]< GET_CURRENT_CALLS {[id=1,ACTIVE,toa=129,norm,mo,als=0,voc,noevp,7012406542,cli=0,name='(null)',0}
04-29 09:47:48.971    84   294 I Gecko   : RIL Worker: [0] Handling parcel as REQUEST_DIAL
04-29 09:47:48.971    84   294 I Gecko   : RIL Worker: [0] Create a pending outgoing call.
04-29 09:47:49.001    84   294 I Gecko   : RIL Worker: [0] Disconnect pending outgoing call
04-29 09:47:49.631    84    84 I Gecko   : -*- RadioInterface[0]: Received message from worker: {"rilMessageType":"callDisconnected","call":{"number":"6509605939","state":2,"callIndex":4294967295,"isOutgoing":true,"isEmergency":false,"isConference":false,"failCause":"UnspecifiedError"},"rilMessageClientId":0}

04-29 09:47:50.531  1267  1267 I log     : <4>0[ 670.371184] lowmem_shrink select 1195 ((Preallocated a), adj 10, size 4666, to kill

Comment 10

[shawn ku [:sku]]

Hi TingYuan:
 Could you please have a look of this issue to see anything weird?

Thanks!!
Shawn

Comment 11

[Ting-Yuan Huang]

Before applications are killed, their nice values were changed to 18, which suggests that their oom_adj were likely changed to 20MB except for preallocated-app, whose oom_adj is changed to 20MB when becoming other applications. I think this is not a problem in low-memory-killer, although it can be a problem with low-memory-killer (if there are some critical regions that preallocated-app shouldn't be accidentally killed).

By the way, can the pull-down menu (system app) or power button work when the problem occurred? Did logcat continue printing logs after the UI frozen?

Comment 12

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

The pull-down menu and power button do not work after this has occured.  I did another log cat and the only thing that continues to report is the following once every 10 seconds.

04-30 09:48:42.583: E/slog(101): check_available_volume: statfs return err! [2]

Comment 13

[Ting-Yuan Huang]

After the last b2g process (Preallocated, 846) being killed, the CPU time of b2g increased 24.9 seconds in 27 seconds (wall clock). I'll try to reproduce the problem to find out on what b2g was spinning.

Comment 14

[Ting-Yuan Huang]

It seemed to be trapped in an infinite loop in gaia. The gaia_build_defer_index.js was minimized so I don't know what exactly happened. @Tim, may I know your opinion?

0 localized() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":131]
1 ll10n_get() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":9]
2 ut_addEllipsis() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":129]
3 hc_formatPhoneNumber() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":248]
4 lookupContact() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":246]
5 anonymous() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":57]
6 getItemOnSuccess() ["app://callscreen.gaiamobile.org/gaia_build_defer_index.js":19]

Comment 15

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Could you upload your gaia_build_defer_index.js and needinfo :etienne? Thanks.

Comment 16

[Ting-Yuan Huang]

Attachment: gaia_build_defer_index.js

Comment 17

[Tim Guan-tin Chien [:timdream] (please needinfo)]

I am reading a while() loop in line 131/132 trying to fit the string in the label.

while(fakeView.getBoundingClientRect().width>viewWidth){if(localizedSide=='left'){newPhoneNumber='\u2026'+value.substr(-value.length+counter);}else if(localizedSide=='right'){newPhoneNumber=value.substr(0,value.length-counter)+'\u2026';}
fakeView.innerHTML=newPhoneNumber;counter++;}

I wonder if we did something wrong there?

Comment 18

[Etienne Segonzac (:etienne)]

(In reply to Tim Guan-tin Chien [:timdream] (MoCo-TPE) (please ni?) from comment #17)
> I am reading a while() loop in line 131/132 trying to fit the string in the
> label.
> 
> while(fakeView.getBoundingClientRect().
> width>viewWidth){if(localizedSide=='left'){newPhoneNumber='\u2026'+value.
> substr(-value.length+counter);}else
> if(localizedSide=='right'){newPhoneNumber=value.substr(0,value.length-
> counter)+'\u2026';}
> fakeView.innerHTML=newPhoneNumber;counter++;}
> 
> I wonder if we did something wrong there?

We never had any issue (except the bad performance) with this code and it shouldn't be "edgy".

I flashed a fresh v1.3t on my tarako and couldn't reproduce the bug. Same thing with the gaia hash mentioned in the Description.
I go through the exact same steps than on the video except the first call is put on hold and not ended, and the phone doesn't freeze.

Also my gecko/gonk are pretty old so might not be gaia-related.

Comment 19

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Could you update your Gecko/Gonk and try again? We would need your help to identify which API is at fault if this is not a Gaia bug.

Comment 20

[Etienne Segonzac (:etienne)]

(In reply to Tim Guan-tin Chien [:timdream] (MoCo-TPE) (please ni?) from comment #19)
> Could you update your Gecko/Gonk and try again? We would need your help to
> identify which API is at fault if this is not a Gaia bug.

I've been waiting for a machine capable of flashing a tarako for 2 weeks, I'm told it should be ready soon... I'll take another look as soon as soon as my tarako is upgraded.

Comment 21

[Etienne Segonzac (:etienne)]

I'm unable to reproduce this issue on a completely up to date tarako (1.3t obviously).
Also tried calling the tarako and hanging up just as I call the voicemail (to reproduce the video better, since the call doesn't get on hold there) and it worked fine.

Can somebody else try on a up-to-date tarako? The repro rate was 100% so the issue may be fixed :)

Comment 22

[Jason Smith [:jsmith]]

QA Wanted to test this on the latest build.

Comment 23

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

Attachment: 5-6-2014.log

I was able to reproduce this on today's 1.3T, but the repro rate has dropped to 6-8 tries to reproduce instead of 100%.

1.3T Environmental Variables:
Device: Tarako 1.3T MOZ
BuildID: 20140506014003
Gaia: aef737f4eae863949d4b42cd6c17339aec3a5fa0
Gecko: cd0c51278ae5
Version: 28.1
Firmware Version: sp6821a-Gonk-4.0-4-29

I am attaching a log of the reproduction on today's build with RIL debugging turned on.

Comment 24

[Ting-Yuan Huang]

I'm wondering if this is related to workloads, such as contacts, call histories, etc. Jayme, may I know what the workloads are on your devices? I can't reproduce it on a clean Tarako and reference-workload-light seems not help, either.

Comment 25

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

I do not use any workloads and can reproduce this issue on a fresh flash on two separate devices that have no call history, contacts, message history, or additional apps installed.

Comment 26

[David Scravaglieri [:scravag]]

(In reply to Jayme Mercado from comment #25)
> I do not use any workloads and can reproduce this issue on a fresh flash on
> two separate devices that have no call history, contacts, message history,
> or additional apps installed.

Could you please provide a video to see what you are doing exactly ?
Etienne was unable to reproduce this bug and I just tried myself on another Tarako and this is still unreproducible.

Thanks

Comment 27

[David Scravaglieri [:scravag]]

In addition I can say that while the call occurs I can call my voice mail and I can switch back and forth between the two calls without any issue

Comment 28

[Jason Smith [:jsmith]]

QA Wanted to get a video.

Comment 29

[Jayme Mercado [:JMercado] (Inactive 3/4/2016)]

I was unable to reproduce this issue on the latest 1.3T Tarako build.

1.3T Environmental Variables:
Device: Tarako 1.3T MOZ
BuildID: 20140507074613
Gaia: 25a17d9d7143977ea9a81ed310098e326609d248
Gecko: 06216419c171
Version: 28.1
Firmware Version: SP6821a-Gonk-4.0-4-29



I flashed to yesterday's to get another video as requested.  I hadn't noticed until after I had finished the capture that the camera had become crooked.  I can record another if necessary.

http://youtu.be/5KsUh8sfbrQ 

1.3T Environmental Variables:
Device: Tarako 1.3T MOZ
BuildID: 20140506014003
Gaia: aef737f4eae863949d4b42cd6c17339aec3a5fa0
Gecko: cd0c51278ae5
Version: 28.1
Firmware Version: sp6821a-Gonk-4.0-4-29

Comment 30

[Danny Liang [:dliang]]

Duplicated issue to bug 1007598, we have STR w/ higher reporudce rate. Let's track it on bug 1007598.