973596 - [tarako] ringtone takes too long to start when playing music in background

Status: RESOLVED DUPLICATE of bug 990003

(Firefox OS Graveyard :: Gaia::Ringtones, defect, P1)

Description

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

When making a phone call to tarako, caller needs to wait about 4~5 ringtones before tarako start to ring if the tarako is playing musics in background.

Comment 1

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

We did some test and observed:

1. When RIL receives a call state change, it takes 700 ms-1.5 sec to start to launch communication app.
2. After communication app started, it takes about 1 sec to finish loading first page. In the first page, communication app handle system message and find there is a phone call, so it load oncall.html in a new window.
3. oncall.html gets ringtone and volume from settings, and check telephony object for current call state. It takes about 3 seconds before it get current state, then start to handle the incoming call.
4. after about 1 sec, settings value is returned in callback, and ringtone starts.

Loading the second window takes much time. And we tried loading ringtone in the first page, with preallocated process ready, the callee ringtone can start after 1~3 ringtones on caller side.

Comment 2

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

Fabrice was working on a patch to run the dialer in the main process which helped a lot here.

Comment 3

[Gabriele Svelto [:gsvelto] (PTO)]

We probably want to fix bug 873284 for this too. That bug was originally filed precisely for this kind of issues. I'll refresh the patch there as it's bit-rotted.

Comment 4

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I think tuning communication app is also worth to try, thus we can keep communication app oop.

Comment 5

[Steve Chung [:steveck]]

Attachment: 0001-ringtone-test.patch

Hi Etienne, it's a test WIP that move ringtone and vibrate related logic from oncall to dialler directly. Do you think it's feasible to take this changes? It seems risky to derive the ringtone/vibrate logic from call screen.
Besides of that, it still has a bug that settings_url.js could not be loaded in LazyLoader and we could not get phoneSoundURL in the patch... If you feel ok to give this patch a try, do you have any idea about the timing for loading settings_url? Thanks.

Comment 6

[Steve Chung [:steveck]]

Attachment: 0001-ringtone-test.patch

settings_url seems not available for lazyload, so I move it to html part for testing.
Hi Patrick, here is the WIP patch that will trigger the ringtone before opening the call screen. The vibration part has some problem but ringtone is working, thanks.

Comment 7

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Attachment: Rebased on 1.3t

Comment 8

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

(In reply to Patrick Wang (Chih-Kai Wang) (:kk1fff) from comment #7)
> Created attachment 8378120 [details] [diff] [review]
> Rebased on 1.3t

Note that I moved openCallScreen() to the line after handleFirstIncoming(), so ringtone can start before attempting to open a new window.

Comment 9

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Comment on attachment 8377996 [details] [diff] [review]
0001-ringtone-test.patch

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

Thanks, Steve. This does help. In my local test, with this patch, tarako can start to ring within 2-3 ringtones on caller side.

Comment 10

[Steve Chung [:steveck]]

Comment on attachment 8378120 [details] [diff] [review]
Rebased on 1.3t

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

Sorry I missed the feedback for Etienne.
Hi Etienne, this patch is our quick test patch that move all the ringtone/vibrate logic from call screen to dialer call handler(before opening call screen). The performance of the screen opening should be improved for the best case, but we might still need a backup solution in gaia dialer side. Do you think moving the ringtone play timing is a feasible solution here, or it might cause side effect which could not be fixed easily ?

Comment 11

[Etienne Segonzac (:etienne)]

Comment on attachment 8378120 [details] [diff] [review]
Rebased on 1.3t

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

feeback- because of the lack of consideration for outgoing calls.

But I don't think this approach is going to work, in order to vibrate we need our document to be visible.
The main app window's document *isn't* when the app is in background. And even if the app is in foreground, when the call screen comes in it will hide the main app window and stop the vibration.

So without gecko a change, the vibration needs to happen in the call screen. And I feel pretty strongly that ringing and vibrating should be handled in the same place.

Sorry :/

::: apps/communications/dialer/js/dialer.js
@@ +173,5 @@
>      telephony.oncallschanged = function dialer_oncallschanged(evt) {
>        if (telephony.calls.length !== 0) {
>          openCallScreen();
> +        if (telephony.calls.length === 1) {
> +          handleFirstIncoming(telephony.calls[0]);

you did not check that this was an incoming call...
We don't want to to ring/vibrate on outgoing calls :)

Comment 12

[Steve Chung [:steveck]]

Thanks for the feedback and reminder. I know I ignore some scenario jsut for ringtone work, but default vibration behavior[1] make this patch not possible to be applied. I agree ringtone and vibration should be handled in the same place, and I see not much benifit but regression if we change the vibration behavior for futher workaround.

[1] http://dxr.mozilla.org/mozilla-central/source/dom/base/Navigator.cpp#729

Comment 13

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

(In reply to Steve Chung [:steveck] from comment #12)
> Thanks for the feedback and reminder. I know I ignore some scenario jsut for
> ringtone work, but default vibration behavior[1] make this patch not
> possible to be applied. I agree ringtone and vibration should be handled in
> the same place, and I see not much benifit but regression if we change the
> vibration behavior for futher workaround.

I don't think we should change the behavior of vibration, either.

I've tried preloading another tab to shorten latency of opening oncalls.html, but it doesn't seem help much.

Comment 14

[Etienne Segonzac (:etienne)]

(In reply to Patrick Wang (Chih-Kai Wang) (:kk1fff) from comment #13)
> (In reply to Steve Chung [:steveck] from comment #12)
> > Thanks for the feedback and reminder. I know I ignore some scenario jsut for
> > ringtone work, but default vibration behavior[1] make this patch not
> > possible to be applied. I agree ringtone and vibration should be handled in
> > the same place, and I see not much benifit but regression if we change the
> > vibration behavior for futher workaround.
> 
> I don't think we should change the behavior of vibration, either.
> 
> I've tried preloading another tab to shorten latency of opening
> oncalls.html, but it doesn't seem help much.

We worked a lot on making index.html load fast in the past, but never looked at oncall.html.
We could probably do the same kind of work (lazy loading...) to help on the gaia side.

Let us know if we need to prioritize that.

Comment 15

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

(In reply to Etienne Segonzac (:etienne) from comment #14)
> We worked a lot on making index.html load fast in the past, but never looked
> at oncall.html.
> We could probably do the same kind of work (lazy loading...) to help on the
> gaia side.
> 
> Let us know if we need to prioritize that.

Thanks, Etienne! It would be good if you can prioritize that. We will need improve the ringtone latency for 1.3T.

Comment 16

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I used boot image from today's QA build, now the callee ringtone can start in 2-3 ringtones.

Comment 17

[Etienne Segonzac (:etienne)]

Made some good progress, will have patches tomorrow.
But note that I'm working on the call screen load time itself, nothing related to the audio channels when having a music in the background. We should probably use separate bugs.

Comment 18

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

triage: 1.3T+, this is needed for tarako

Comment 19

[Etienne Segonzac (:etienne)]

I found 3 ways to make the performance better on the gaia side and filed corresponding bugs.

We should see it as a buffet, and land/uplift only the ones to our taste in term of gain/risk :)

* bug 979406 is really simple and not risky at all, for a ~600ms gain
* bug 979419 will be a bigger patch, risky but manageable, for a ~300ms gain on a keon (probably a bit more on a tarako)
* bug 979426 will probably be too risky anyway for an uplift, it's here for investigation, we're probably looking at a ~300ms gain here too

Comment 20

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Thanks! Etienne! I will run task tracer to see how we can improve from Gecko.

Comment 21

[bhavana bajaj [:bajaj]]

Waiting for dependencies to resolve.

Comment 23

[Danny Liang [:dliang]]

Update the test result on different kernel build, I record the ringtone 5 times in each build.
1. kernel image on 3/4, commit d55a299649ea077e33cfb9d620ee06819829b9ee
 - The ringtone of tarake (MT) start after 3~4 ringtone of MO device
2. kernel image on 2/25, commit d497083f59b47819c397d3476da3f03d5631f7e8
 - The ringtone of tarake (MT) start after 3~4 ringtone of MO device
3. kernel image on 2/19, commit 2cda7841ce0c4c4d31ef374edbd868c8add6d774
 - The ringtone of tarake (MT) start after 3~4 ringtone of MO device

We also review the kernel change list, and didn't find any change will cause performance improvement recently.

With kernel review and test result, we can confirm there is no improvement in kernel side.

SW version:
Gecko: 0d688e9bda743e80d735b43c4a4c8e205b2e5100
Gaia: d9907660806748c5c06c95b097de2d7b1fc118d8

Comment 24

[Danny Liang [:dliang]]

Attachment: tarako_bootimage.tar.gz

Attached the test image I used

Comment 25

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I did some experiment on killing/suspending other apps during incoming call and measure the time cost from RIL gets call state change to ringtone start. I did each test 5 times, each time I kill comms app and go back to homescreen, then turn the screen off. Here's the average values.

1. Killing all apps (include music app) when receiving a call: 3.7592
2. Killing all apps that not holding audio channel: 4.5144
3. Suspend (SIGSTOP) all apps: 5.9012
4. Change OOM_ADJ to get more memory (1024,1280,1536,4096,5120,6144): 9.4994
5. Don't do anything: 4.6736 (about 2 ringback tones)

As the result suggests, the ringtone starts slowly when memory is not enough, even other apps are not competing for CPU.

Comment 26

[Etienne Segonzac (:etienne)]

We're changing strategy on the gaia side.

We discussed it a lot with Vivien, and vibrating/ringing from the system app is less risky and yields *way* better results.

I'll close bug 979419 and bug 979426 in favor of bug 980984.

Comment 27

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

patrick, seems like you have been working on this. assign this to you for now. please reassign if you are not working on this. thanks

Comment 28

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I tried patch for bug 980984 on tarako, the ringtone starts almost the same time as ringback starts.

Comment 29

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Rebasing task tracer on 1.3t https://github.com/kk1fff/mozgit/tree/task-tracer/1.3t/a3

Comment 30

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

Patrick, do you mind providing some update on this bug? thanks

Comment 31

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

As test in comment 25, it appears that we need to kill music app for launching dialer faster. We will try  to kill music when it affects performance too much (or some import event, like incoming call, is fired), and resume the music app after phone call.

It needs some changes in system app and music app to save the position where music app is playing before it is killed, and relaunch music app and continue to play music after end of phone call.

Comment 32

[Thinker Li [:sinker]]

Could you find some one to handle this?  Store states of playing music before being killed.

Comment 33

[[:fabrice] Fabrice Desré]

Patrick?Thinker, bug 980984 is not enough to improve the situation? It has not been uplifted yet.

Comment 34

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

(In reply to Fabrice Desré [:fabrice] from comment #33)
> Patrick?Thinker, bug 980984 is not enough to improve the situation? It has
> not been uplifted yet.

I have made a rebased version and tried the patch locally. With it, ringtone does start earlier a lot. But UI of answering call still need several rings to show, we need to improve that to make user able to answer/decline the call earlier.

Comment 35

[[:fabrice] Fabrice Desré]

Ok. Reading this bug again, Gabriele has a patch in bug 873284 that could help and never landed. I'd like to not have to kill the music player or run the dialer in-process...

Comment 36

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

(In reply to Thinker Li [:sinker] from comment #32)
> Could you find some one to handle this?  Store states of playing music
> before being killed.

Please ping me again, and :hema and dkuo if this is what we want to do.

Comment 37

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

Gabriele, do you think bug 873284 will help? if so, lets try to get it landed. thanks

Comment 38

[Gabriele Svelto [:gsvelto] (PTO)]

It could be useful if we're triggering that condition. I'm not clearing the needinfo flag because I want to test it tomorrow and see if it helps. One of the reasons why my patch never landed is that it lacks unit tests so I'll try to put those together if it turns out to be useful.

Comment 39

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I've tried the patch. It doesn't seem help, since memory pressure is not triggered when receiving a call with music in background.

Comment 40

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

the team is going to try https://bugzilla.mozilla.org/show_bug.cgi?id=983541#c15 first to see if it helps with this bug

Comment 41

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

I've tried the patch, it saves about 1 MB (10MB USS -> 8.7MB USS) of RAM. However, UI of answering call doesn't show up sooner. It takes about 8.5 seconds to show, the value is almost the same as how it takes without the patch.

I did some tests to see how long it takes from RIL received call state change to UI is displayed, here's the result:

1. Not playing music, screen off: 4.75 sec
2. playing music in background, screen off: 8.10 sec
3. playing music in background and kill music app when phone call incoming, screen off: 4.92 sec

Comment 42

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Attachment: Log RIL receiving call state change

Log timestamp of receving call state change.

Comment 43

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Attachment: Log timestamp of UI starting to display (Gaia)

Comment 44

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Attachment: Get time difference between receiving call state change and starting to display UI

Comment 45

[thomas tsai]

If communication app is always in the background as a content process, dailer UI can respond to MT call after a ring tone.

Comment 46

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

(In reply to Patrick Wang (Chih-Kai Wang) (:kk1fff) from comment #41)
> 
> 1. Not playing music, screen off: 4.75 sec
> 2. playing music in background, screen off: 8.10 sec
> 3. playing music in background and kill music app when phone call incoming,
> screen off: 4.92 sec

3. playing music in background and kill music app when phone call incoming, screen off: 4.92 sec
I'd like to explore this option for lower end devices if we don't get much further on this. ni? product

Comment 47

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

also Steven for comment 46

Comment 48

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

Whatever happened to running the dialer in the parent process?

Comment 49

[[:fabrice] Fabrice Desré]

(In reply to Kyle Huey [:khuey] ([e-mail]) from comment #48)
> Whatever happened to running the dialer in the parent process?

That would be fine if we could run only the dialer. But it's part of the communication app, and as such also runs the contacts app that import 3rd party contacts. So that would be a last resort solution.

Comment 50

[Steven Yang [:styang]]

(In reply to Joe Cheng [:jcheng] from comment #46)
> (In reply to Patrick Wang (Chih-Kai Wang) (:kk1fff) from comment #41)
> > 
> > 1. Not playing music, screen off: 4.75 sec
> > 2. playing music in background, screen off: 8.10 sec
> > 3. playing music in background and kill music app when phone call incoming,
> > screen off: 4.92 sec
> 
> 3. playing music in background and kill music app when phone call incoming,
> screen off: 4.92 sec
> I'd like to explore this option for lower end devices if we don't get much
> further on this. ni? product

It's the fundamental requirement. I'm afraid it's not an option for our partner.

Comment 51

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Another option is that we can play music in system app. I tried playing music in system app, the UI displays after 3~4 seconds (1 ~ 1.5 ringbacks), which is almost the same as not playing music in background.

To play music in system app, we can turn music app into a "controller" which tells system app how to play the music through IAC. When the call is coming, we simply kill all of the apps to release the memory, to make dialer launch sooner. After call ends, system app resumes the music and launches music app, and music app can get necessary info from system and prepare UI in background.

Comment 52

[Dominic Kuo [:dkuo]]

(In reply to Patrick Wang (Chih-Kai Wang) (:kk1fff) from comment #51)
> Another option is that we can play music in system app. I tried playing
> music in system app, the UI displays after 3~4 seconds (1 ~ 1.5 ringbacks),
> which is almost the same as not playing music in background.
> 
> To play music in system app, we can turn music app into a "controller" which
> tells system app how to play the music through IAC. When the call is coming,
> we simply kill all of the apps to release the memory, to make dialer launch
> sooner. After call ends, system app resumes the music and launches music
> app, and music app can get necessary info from system and prepare UI in
> background.

Thanks Patrick, looks like if we put the audio element in system and use it to play the music, not only gets better launch time for the dialer ui, but also saves memory during the call, though these will need extra works to move the audio element from music to system, then communicates with each other via IAC. But since this should be the most workable solution on tarako for now, let's use this approach and I am going to implement in bug 987022.

Comment 53

[Marvin Khoo [:Marvin_Khoo]]

As this is fundamental req, keep monitor if 987022 improves here and discuss further actions if needed.
adding Ravi into this bug.

Comment 54

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Observe of the difference between playing music and not playing music:

playing music:

ring: 5.986

system
user:     44.07% 3.53 sec
sys:      40.70% 3.26 sec
nice:     2.12%
idle:     13.11%
iowait:   0.00%
irq:      0.00%
sirq:     0.00%
pgin:     4397
pgout:    10110
swpin:    1067
swpout:   2471

b2g(81)
majflt:   508
minflt:   6704
utime:    1.29 secs
stime:    0.71 secs

comms(12061)
majflt:   518
minflt:   10308
utime:    2.07 secs
stime:    1.04 secs

not playing music:

ring: 3.998

system
user:     54.05% 3.0 sec
sys:      31.17% 1.73 sec
nice:     0.00%
idle:     14.77%
iowait:   0.00%
irq:      0.00%
sirq:     0.00%
pgin:     245
pgout:    477
swpin:    61
swpout:   78

b2g(81)
majflt:   24
minflt:   2918
utime:    0.89 secs
stime:    0.28 secs

comms(11652)
majflt:   85
minflt:   7841
utime:    2.1 secs
stime:    0.65 secs

Note the idle time is from the value before ringtone start, there is a short period between last sample and actual start time of ringtone. And there are some other processes (slog and logcat) which compete for cpu time, this experiment is done when those processes are killed.

Comment 55

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

Attachment: measure time used for launching dialer.

Measure time of launching dialer, majflt/minflt of dialer and b2g during this period and stime/utime of all processes on the phone.

Comment 56

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

In some case, I found that a process slog takes about 4 secs system time during incoming call. With this process suspended, the launch time of incoming call screen from 9 secs to 4 secs. The process doesn't present in unagi, is this a devices specific process? and what is this for?

Comment 57

[James Zhang (Spreadtrum)]

Slog is in spreadtrum userdebug build, for filed test and catch adb log.
You can try user build, it hasn't slog process.

Comment 58

[Patrick Wang (Chih-Kai Wang) (:kk1fff)]

We have tested WIP patch for bug 987022. It improves the launch time of comms app when playing music background. However, if home screen restarts before comms app, it would slow down the launching of comms app. We will need to prevent home screen from being restarted before comms app launch.

Comment 59

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

We should also revisit this when bug 990003 lands.

Comment 60

[Keven Kuo [:kkuo]]

QAWANTED, to confirm if this bug is still valid after bug 990003 landed

Comment 61

[Brian Huang [:brianhuang][:brhuang]]

Mike, pls help to confirm. After check, pls remove qawanted. Thanks.

Comment 62

[Mike Lien[:mlien]]

verify with below build and it's fine
Gaia      c62bff0bfb8b069c962dfae2640e931cc9ad1bdf
Gecko     https://hg.mozilla.org/releases/mozilla-b2g28_v1_3t/rev/7e764399b4fc
BuildID   20140415164003
Version   28.1

Comment 63

[Brian Huang [:brianhuang][:brhuang]]

dup to 990003