Closed Bug 819080 Opened 7 years ago Closed 6 years ago

[FMRadio] "ready to use" perf measurement

Categories

(Firefox OS Graveyard :: Gaia::FMRadio, defect, P2)

All
Gonk (Firefox OS)
defect

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: pla, Assigned: hub)

References

Details

(Keywords: perf, Whiteboard: [c=automation p=4 s= u=] interaction)

Attachments

(2 files, 4 obsolete files)

What makes it feel slow/broken?

It takes a little longer to startup the FM Radio app after a device reset/startup.  Timed consistently at 2.3 seconds on Unagi running Dec. 6th nightly.  David Clarke to provide more accurate, recent numbers.

Did it prevent you from doing what you wanted? Why?

FM Radio is a core entertainment app for our target launch market.  While 2.3 seconds isn't too bad, any gains we can make here would be important.

How does this make you feel?

[ ]  :)  I feel happy about it
[X]  :|  Meh
[ ]  :(  I'm upset
[ ] >:O  I'm angry

Device: Original numbers from Unagi, Dec. 6th nightly.  David Clarke to get Otoro numbers.

Details:

B2G on Unagi:               2.3 seconds
Android ICS 4.0.4 on Otoro: 1.6 seconds

David Clarke to provide updated B2G on Otoro numbers.

Bonus: can you attach a video of the problem?
See metabug 814981
Hi Peter,

The long start up time is resulted from that when we enable FM radio, hal takes about 2.2 seconds to get ready. If we want shorter time, we may need vendor's support.
Whiteboard: interaction → interaction [c= ]
Peter, is this still a problem on Unagi? Is it also a problem devices that ships (Alcatel/TCL, ZTE Open) ?

Strangely the problem doesn't show up in datazilla, but I'm not sure that we actually measure it properly.

Thanks,
Flags: needinfo?(pla)
Assignee: nobody → hub
Status: NEW → ASSIGNED
Whiteboard: interaction [c= ] → interaction [c= p=]
Attached patch Debug patch just for info. (obsolete) — Splinter Review
This just a debugging patch.

Apply it, then start the FMRadio app.

in the logcat we should see:

E/GeckoConsole(  112): Content JS LOG at app://system.gaiamobile.org/js/window_manager.js:730 in appLoadedHandler: apploadtime sent
E/GeckoConsole(  501): Content JS LOG at app://fm.gaiamobile.org/js/fm.js:189 in enableFMRadio: enabling the FMRadio

That show the HAL is initialised AFTER the load startup measurement. This confirm why it isn't measure in the perf bigdata.
Whiteboard: interaction [c= p=] → interaction [c= p=3]
(clearing needinfo, the issue is there)
Flags: needinfo?(pla)
With this Gecko patch we measure the initialization time and log it into the logcat. Look for "Perf:FMRadio:Enable"
Comment on attachment 793438 [details] [diff] [review]
Bug 819080 - Part 1: Timing of the FM Radio hardware initialisation.

Adding Pin Zhang to review.
Attachment #793438 - Flags: review?(pzhang)
Comment on attachment 793438 [details] [diff] [review]
Bug 819080 - Part 1: Timing of the FM Radio hardware initialisation.

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

Will the log message be shown in production? If not, we should use |debug| instead of |widow.dump|.

::: dom/fm/DOMFMRadioParent.jsm
@@ +335,4 @@
>      this._enabling = true;
>      let self = this;
>  
> +    let t0 = 0;

You don't have to init the variable here.

@@ +340,4 @@
>      FMRadio.addEventListener("enabled", function on_enabled() {
> +      let t1 = Date.now();
> +      let timing = t1 - t0;
> +      dump("Perf:FMRadio:Enable " + timing + " ms.");

I think |dump| won't append |\n| for you, so the log message will be messed with the following one, how about:
  dump("Perf:FMRadio:Enable " + (Date.now() - timeStart) + " ms.\n");
then you don't have to define the temp vars |t1| and |timing|.

@@ +362,4 @@
>        ppmm.broadcastAsyncMessage("DOMFMRadio:frequencyChange", { });
>      });
>  
> +    t0 = Date.now();

t0 doesn't mean anything, how about rename it to startTime, and you can init it here intead in line338: 
  let startTime = Date.now();
Attachment #793438 - Flags: review?(pzhang) → review-
Addressed comment from previous review.
Attachment #793438 - Attachment is obsolete: true
Attachment #793816 - Flags: review?(pzhang)
Sorry, this is actually the version with all the comments addressed.
Attachment #793816 - Attachment is obsolete: true
Attachment #793816 - Flags: review?(pzhang)
Attachment #793820 - Flags: review?(pzhang)
Attachment #793820 - Flags: review?(pzhang) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/ec5837779ede
Whiteboard: interaction [c= p=3] → interaction [c= p=3] leave-open
Whiteboard: interaction [c= p=3] leave-open → interaction [c= p=3] [leave-open]
The test is implemented as such:

https://bugzilla.mozilla.org/show_bug.cgi?id=819080

Not sure how to go further to have it added to DataZilla for tracking.
(In reply to Hubert Figuiere [:hub] from comment #12)
> The test is implemented as such:
> 
> https://bugzilla.mozilla.org/show_bug.cgi?id=819080

Oops I meant https://github.com/mozilla/b2gperf/pull/14
Whiteboard: interaction [c= p=3] [leave-open] → interaction [c= p=1] [leave-open]
(In reply to StevenLee from comment #1)
> Hi Peter,
> 
> The long start up time is resulted from that when we enable FM radio, hal
> takes about 2.2 seconds to get ready. If we want shorter time, we may need
> vendor's support.

Steven, We are in the process of setting up automatic performance measurements for this. How do we go on getting the vendor's help to have an engineer fix the actual issue?

Thanks,
Flags: needinfo?(slee)
Whiteboard: interaction [c= p=1] [leave-open] → interaction [c= p=4] [leave-open]
Hi Micheal,

Can you find someone to help us on this issue?
Thanks.
Flags: needinfo?(slee) → needinfo?(mvines)
This doesn't seem like that big of a deal TBH:

> How does this make you feel?
> [X]  :|  Meh
Flags: needinfo?(mvines)
Steven, now that we'll have a way to measure this, who can help us (Mozilla) address the issue and make this faster, since according to comment 1, this is a vendor driver issue.

Or maybe it has become a non issue as per comment 16.

Thanks
Flags: needinfo?(slee)
(In reply to Hubert Figuiere [:hub] from comment #17)
> Steven, now that we'll have a way to measure this, who can help us (Mozilla)
> address the issue and make this faster, since according to comment 1, this
> is a vendor driver issue. 
> Or maybe it has become a non issue as per comment 16.
I think we may need the feedback of PM or UX. If they want to make the startup time shorted, we need the vendor's help. If not, it should not be an issue.
Flags: needinfo?(slee)
So basically the last rewrite of the FMRadio module completely broke the test as the log entry has disappeared.

*sigh*
In light of everything, morphing this bug into "write perf test".
Summary: [Gaia::FMRadio] Long initial startup time for FMRadio app → [FMRadio] "ready to use" perf measurement
Target Milestone: --- → 1.2 C3(Oct25)
Depends on: 915158, 915156
No longer blocks: 814981
Priority: -- → P2
Target Milestone: 1.2 C3(Oct25) → ---
QA Contact: dclarke
Test writing ongoing in this branch https://github.com/hfiguiere/gaia/compare/bug819080-perf
Attached file Pull request (obsolete) —
Attachment #785887 - Attachment is obsolete: true
Whiteboard: interaction [c= p=4] [leave-open] → [c=automation p=4 s= u=] interaction [leave-open]
Attached file Pull request
Attachment #8340564 - Attachment is obsolete: true
Comment on attachment 8343828 [details] [review]
Pull request

r?: Julien for the test part, pzhang for the fm radio part.
Attachment #8343828 - Flags: review?(pzhang)
Attachment #8343828 - Flags: review?(felash)
+    PerformanceTestingHelper.dispatch('fm-radio-enabled');
+    PerformanceTestingHelper.dispatch('startup-path-done');

The event 'startup-path-done' is defined in tests/performance/startup_events_test.js, right? but what 'fm-radio-enabled' is used for?
(In reply to Hubert Figuiere [:hub] from comment #19)
> So basically the last rewrite of the FMRadio module completely broke the
> test as the log entry has disappeared.
> 
> *sigh*

I'm sorry rewriting broke this, :(
(In reply to Pin Zhang [:pzhang] from comment #26)
> (In reply to Hubert Figuiere [:hub] from comment #19)
> > So basically the last rewrite of the FMRadio module completely broke the
> > test as the log entry has disappeared.
> > 
> > *sigh*
> 
> I'm sorry rewriting broke this, :(

No worries about that.
(In reply to Pin Zhang [:pzhang] from comment #25)
> +    PerformanceTestingHelper.dispatch('fm-radio-enabled');
> +    PerformanceTestingHelper.dispatch('startup-path-done');
> 
> The event 'startup-path-done' is defined in
> tests/performance/startup_events_test.js, right? but what 'fm-radio-enabled'
> is used for?

These are just "keys" and not events - they mark a specific timing ; they are data for the x-moz-perf event that is sent in shared/js/performance_testing_helper.js. Only the test needs to know about them.
(In reply to Hubert Figuiere [:hub] from comment #28)
> (In reply to Pin Zhang [:pzhang] from comment #25)
> > +    PerformanceTestingHelper.dispatch('fm-radio-enabled');
> > +    PerformanceTestingHelper.dispatch('startup-path-done');
> > 
> > The event 'startup-path-done' is defined in
> > tests/performance/startup_events_test.js, right? but what 'fm-radio-enabled'
> > is used for?
> 
> These are just "keys" and not events - they mark a specific timing ; they
> are data for the x-moz-perf event that is sent in
> shared/js/performance_testing_helper.js. Only the test needs to know about
> them.

The helper is designed to catch all events _until_ "startup-path-done" is received and log their timestamp :) That's the beauty of it: you can add markers whenever you want.
Attachment #8343828 - Flags: review?(pzhang) → review+
Comment on attachment 8343828 [details] [review]
Pull request

I don't see it working on my device?

Even with a connected headphone, it never seems to stop.
Comment on attachment 8343828 [details] [review]
Pull request

Also, you need to update the unit tests, they currently fail because PerformanceTestingHelper is missing.

You just need to load the file at apps/communications/contacts/test/unit/mock_performance_testing_helper.js, maybe move it to shared/, and use the mocks_helper to manage it.
Comment on attachment 8343828 [details] [review]
Pull request

r- until these changes are done.
Attachment #8343828 - Flags: review?(felash) → review-
(In reply to Julien Wajsberg [:julienw] from comment #31)
> Comment on attachment 8343828 [details] [review]
> Pull request
> 
> Also, you need to update the unit tests, they currently fail because
> PerformanceTestingHelper is missing.
> 
> You just need to load the file at
> apps/communications/contacts/test/unit/mock_performance_testing_helper.js,
> maybe move it to shared/, and use the mocks_helper to manage it.

Since when did that change? I tested it yesterday.
I just tested the standalone file, maybe the full suite is working because the mock is loaded elsewhere. But individual files should work in a standalone way as well.
Doing a |APP=fm make test-perf| or just |make test-perf| works. 

I don't get what the issue that you are having.
Flags: needinfo?(felash)
I was not talking about the perf tests but about the unit tests.
Flags: needinfo?(felash)
Comment on attachment 8343828 [details] [review]
Pull request

Updated pull request to deal with the unit test failure.

The added change is in apps/fm/test/unit/fm_test.js
Attachment #8343828 - Flags: review- → review?(felash)
Addressed the nits.
Comment on attachment 8343828 [details] [review]
Pull request

r=me

that was me being stupid and not flashing the new "fm" app...

Thanks
Attachment #8343828 - Flags: review?(felash) → review+
(In reply to Julien Wajsberg [:julienw] from comment #39)

> that was me being stupid and not flashing the new "fm" app...


You don't want to know how many time this happened to me :-)

Thanks !
Travis is green.

Merged.
https://github.com/mozilla-b2g/gaia/commit/6d8c461b03efe18bcdea34386cdcfbe612b098e0
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Whiteboard: [c=automation p=4 s= u=] interaction [leave-open] → [c=automation p=4 s= u=] interaction
No longer blocks: gaia-perf-events
You need to log in before you can comment on or make changes to this bug.