Closed Bug 1088118 Opened 7 years ago Closed 7 years ago

Switch applications to use User Timing to mark performance events

Categories

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

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: Eli, Assigned: Eli)

References

Details

(Keywords: perf, Whiteboard: [systemsfe])

Attachments

(3 files, 2 obsolete files)

For a more efficient performance test flow, we need to decouple the atom scripts from the eventing mechanisms currently in place as they actually incur a performance hit in order to measure performance. By utilizing the User Timing API (bug 782751), we can eliminate much use of atom scripts altogether. Until User Timing is complete though, this functionality will be shimmed in Gaia. We can then switch to using proper performance markers.
Whiteboard: [systemsfe]
Depends on: 1091990
This patch augments the current performance testing metrics with new User Timing markers to support the future performance testing style and framework.
Attachment #8533873 - Flags: review?(kgrandon)
Attachment #8533873 - Flags: review?(jlal)
Hmm, this touches a lot of apps - I wonder if we need reviews from every app peer here, or if we can just bypass that.

Also is the plan here to remove the old performance Custom Events?
I wasn't for sure if we would need a review from every peer, but I will go that route if we are supposed to. Also the old custom events won't be removed until we deprecate Datazilla.
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Strictly speaking we should and I think this helps us actually because we can raise more awareness of the work that is going on.
Attachment #8533873 - Flags: review?(jlal)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

See comment 1 and ni? with any questions.
Attachment #8533873 - Flags: review?(timdream)
Attachment #8533873 - Flags: review?(m)
Attachment #8533873 - Flags: review?(jrburke)
Attachment #8533873 - Flags: review?(gaye)
Attachment #8533873 - Flags: review?(francisco)
Attachment #8533873 - Flags: review?(felash)
Attachment #8533873 - Flags: review?(drs.bugzilla)
Attachment #8533873 - Flags: review?(dkuo)
Attachment #8533873 - Flags: review?(dflanagan)
Attachment #8533873 - Flags: review?(arthur.chen)
Attachment #8533873 - Flags: review?(21)
Attachment #8533873 - Attachment description: Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679/files → Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Removing the r? flag for me because I don't have enough context to review this patch. Specifically, I don't know what these performance.mark() calls actually do. Once you've explained some more, I'm happy to review the changes for Gallery, Video, Music and FM radio, but for Camera you should probably add :wilsonpage as a reviewer.

I see in usertiming.js that the calls to mark are producing log messages and I'm guessing that that is the point of this patch. But that raises more questions for me...

1) When gecko implements the user timing API, is it going to produce logging output just like this shim? Or are you still going to have to load a shim to add the logging?

2) If logging is automatically built into performance.mark() could you add the event dispatch stuff there too, so that we can replace that weird event stuff?

3) I'm worried about the size of usertiming.js. Since your patch only uses performance.mark() (I think) could we get away with a smaller shim that only implements that one method to do the logging you need without all the other complexity?  

4) In particular, I worry about the call to mozApps.getSelf(). Actually, I have no idea what its performance characteristics are, but it seems like the kind of thing that could slow down app startup time.  Doesn't console.log() already show the app name? And wouldn't window.location give you the entry point?

5) When the user timing spec is complete, is it going to do everything you need? Or would it make more sense to just implement PerformanceTestingHelper.mark() which will do the logging and event generation and anything else you need?  This function could call performance.mark if it is defined or generate logs if it is not defined.  My point is that it would be nice for app authors to only have to load one shared file instead of two and mark each point with one function call instead of two.
Attachment #8533873 - Flags: review?(dflanagan)
I'll try and address all your questions:

(In reply to David Flanagan [:djf] from comment #6)
> Comment on attachment 8533873 [details]
> Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679
> 
> Removing the r? flag for me because I don't have enough context to review
> this patch. Specifically, I don't know what these performance.mark() calls
> actually do. Once you've explained some more, I'm happy to review the
> changes for Gallery, Video, Music and FM radio, but for Camera you should
> probably add :wilsonpage as a reviewer.

The User Timing API [1] allows for user-defined performance markers and measurements which take advantage of high-resolution time, e.g. the same kind produced by performance.now(). In order to decouple our applications from atom scripts, testing helpers, and shims, the long-term plan is to move everything towards markers and measurements created via this User Timing API.

> I see in usertiming.js that the calls to mark are producing log messages and
> I'm guessing that that is the point of this patch. But that raises more
> questions for me...
> 
> 1) When gecko implements the user timing API, is it going to produce logging
> output just like this shim? Or are you still going to have to load a shim to
> add the logging?

Yes, once User Timing is properly implemented in Gecko, there will be NSPR logs to create appropriate log output for us to capture during the testing process. The shim will no longer be necessary.

> 2) If logging is automatically built into performance.mark() could you add
> the event dispatch stuff there too, so that we can replace that weird event
> stuff?

When User Timing is in Gecko, we won't need the CustomEvents at all. They only exist to keep our current performance tests running until the time comes where we can deprecate Datazilla. See my message to dev-gaia [2].

> 3) I'm worried about the size of usertiming.js. Since your patch only uses
> performance.mark() (I think) could we get away with a smaller shim that only
> implements that one method to do the logging you need without all the other
> complexity?  

I personally only require the pieces from performance.mark and performance.measure. If we want to slim this down by removing the portion that allows you to fetch entries back out of User Timing, we can consider that, although it will have an effect on fetching the application name again and I will need to rethink this portion.

> 4) In particular, I worry about the call to mozApps.getSelf(). Actually, I
> have no idea what its performance characteristics are, but it seems like the
> kind of thing that could slow down app startup time.  Doesn't console.log()
> already show the app name? And wouldn't window.location give you the entry
> point?

console.log shows app names like "Homescreen" for verticalhome, "Phone" for communications/dialer, and "Contacts" for communications/contacts. Using mozApps seemed to be the only consistent way to get an application's name to use as a key for creating log entries. I welcome more thoughts around this if you know of better alternatives.

> 5) When the user timing spec is complete, is it going to do everything you
> need? Or would it make more sense to just implement
> PerformanceTestingHelper.mark() which will do the logging and event
> generation and anything else you need?  This function could call
> performance.mark if it is defined or generate logs if it is not defined.  My
> point is that it would be nice for app authors to only have to load one
> shared file instead of two and mark each point with one function call
> instead of two.

Yes, User Timing will do everything we currently have planned for it to accomplish. Once it has been implemented in Gecko, we will no longer have the need for the shim, the performance testing helper, or any atom scripts that the Marionette performance tests require. The Gecko implementation will create log entries as well as place markers and measurements in devtools.

Did I answer all of your questions?

[1] http://www.w3.org/TR/user-timing/
[2] https://groups.google.com/d/msg/mozilla.dev.gaia/PR7AHRmZuj4/dTa5JYmNDDIJ
(In reply to :Eli Perelman from comment #7)
> console.log shows app names like "Homescreen" for verticalhome, "Phone" for
> communications/dialer, and "Contacts" for communications/contacts. Using
> mozApps seemed to be the only consistent way to get an application's name to
> use as a key for creating log entries. I welcome more thoughts around this
> if you know of better alternatives.

I misspoke here, I meant to say that both communications/dialer and communications/contacts both create log entries under "Communications". I could make an assumption that Communications is meant for the currently open app and it would eliminate the need for this portion of code, but that will be making assumptions for any other apps also using the entry point model. It should be OK for now though.
Also of note, I have to make this same assumption for the upcoming memory tests, so maybe this isn't such a bad thing after all.
I'd like to properly understand what is the improvement you get with this patch.

I agree with all that David said in comment 6, and I actually see a perf regression at launch time when comparing on Buri.

As a rule of thumb, we should not do any work when merely executing the file, and while I haven't closely measured this, I'm quite sure the call to mozApps is what is costly here.
Attachment #8533873 - Flags: review?(felash)
Does it also limit our ability to bind events to those bootstrap marks? ("Bind keys only after chrome-ready" kind of things)
I will go ahead and remove the call to mozApps from the code, with the caveat that we will be unable to identify performance markers in the log that originate from a single app with different entry points e.g. Phone and Contacts. This ability may be improved once we move User Timing to Gecko, but that I am unsure of.

Also, there is no way we can prevent a regression with this patch. Including and executing another script will introduce some overhead until: (1) we deprecate Datazilla and remove the performance testing helper and (2) the User Timing shim can be removed once it has been implemented in Gecko. So we will be accepting a regression in performance in the short term while I work to get these points resolved, and then performance will actually improve.

(In reply to Zibi Braniecki [:gandalf] from comment #11)
> Does it also limit our ability to bind events to those bootstrap marks?
> ("Bind keys only after chrome-ready" kind of things)

At the moment, yes. I am working on getting a marker notification functionality added to the spec [1], but I don't foresee that happening very quickly. Fortunately what you are speaking of isn't currently used anywhere in Gaia, but I understand how it might be useful. In those cases, I would say triggering an event along with adding the performance marker is the right stopgap.

[1] http://lists.w3.org/Archives/Public/public-web-perf/2014Dec/0016.html
In removing the call to mozApps, I can also remove some of the other code from the User Timing shim, again with a caveat that the shim will not be a complete implementation of the spec.
Just FYI that I believe we are aiming to split the phone and contacts application during this release, for now it would probably be fine to just group the apps, or I would assume that you could do some manual parsing of the window.location value if you wanted.
(In reply to :Eli Perelman from comment #12)
> At the moment, yes. I am working on getting a marker notification
> functionality added to the spec [1], but I don't foresee that happening very
> quickly. Fortunately what you are speaking of isn't currently used anywhere
> in Gaia, but I understand how it might be useful. In those cases, I would
> say triggering an event along with adding the performance marker is the
> right stopgap.

Sure, I just wanted to clarify that the scope of possible uses changes with this switch.
Eli,

Thanks for the answers, I think I understand this now. One more question: the user timing spec includes some recommended mark names that seem to have overlap with ours. Are you intentionally using names other than the recommended ones?
Flags: needinfo?(eperelman)
Yes, and for 2 different reasons.

First, we had raised in a different WebPerf thread that the recommended mark names were inconsistent with the ones already defined in specs like Performance Timing and Navigation Timing, and in hindsight the group had agreed the names were poorly defined. It may still happen that the spec will be amended to rename the offending marks.

Second, only 2 of the marks had a direct correlation to the ones we had defined in bug 996038, `mark_fully_loaded` to `moz-app-loaded` and `mark_above_the_fold` to `moz-app-visually-complete`. We could continue to use our existing event names, but that would be inconsistent with both styles, so we chose to rename our markers consistent to the other specs and err on the side of non-redundant mark names.

Also of note in speaking with the other browser vendors that none of them use the "Recommended" mark names.
Flags: needinfo?(eperelman)
(In reply to Julien Wajsberg [:julienw] from comment #10)
> I'd like to properly understand what is the improvement you get with this
> patch.

To be clearer, the improvement is the eventual removal of all helper and atom scripts from performance testing. Also to decouple the creation of performance events/markers from our performance testing. These improvements will not be immediately realized with this patch, but this patch paves the way for this to happen.
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Pull request has been revised to eliminate extra overhead from User Timing shim, enough only for running performance tests. You currently cannot tell the difference between performance entries in the log with apps that share the same entry point, e.g. Phone and Contacts. This has no effect on the performance tests themselves which can still categorize them correctly.

IMPORTANT: The performance entries API of `getEntries*` cannot be used to fetch User Timing entries using this shim.
Attachment #8533873 - Flags: review?(felash)
Attachment #8533873 - Flags: review?(dflanagan)
Also included in the updated PR are some changes to unit tests that did not know what performance.mark and .measure were.
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

r+ for the FM, Gallery, Music and Video apps. The camera changes also look fine, but I don't have much experience with require.js so I'd prefer that you ask Wilson Page (or Diego Marcos or Justin D'Arcangelo) to review those.

Thanks for simplifying usertiming.js

The changes are so trivial that this review is based on code inspection only. I assume that you have actually run the apps with these changes.
Attachment #8533873 - Flags: review?(dflanagan) → review+
Attachment #8533873 - Flags: review?(wilsonpage)
(In reply to David Flanagan [:djf] from comment #21)
> The changes are so trivial that this review is based on code inspection
> only. I assume that you have actually run the apps with these changes.

That I have, and it runs perfectly in the upcoming performance tests. Thanks for the review!
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

r=me for the settings app.
Attachment #8533873 - Flags: review?(arthur.chen) → review+
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Left some feedback for the email changes in the pull request, flip review back to me when addressed.

I am interested to know more about likely timelines for both the removal of the dependence on datazilla (and therefore removal of that older perf CustomEvent code) and the user timing stuff landing, just for my own education, these topics are newer for me.
Attachment #8533873 - Flags: review?(jrburke)
Attachment #8533873 - Flags: review?(wilsonpage) → review+
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Contacts part looking good
Attachment #8533873 - Flags: review?(francisco) → review+
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Changes made to email, ready for review again. :)
Attachment #8533873 - Flags: review?(jrburke)
(In reply to James Burke [:jrburke] from comment #24)
> I am interested to know more about likely timelines for both the removal of
> the dependence on datazilla (and therefore removal of that older perf
> CustomEvent code)

My goal is to have something deployed by the end of the month, at which point we should be able to start removing all the old events.

(In reply to James Burke [:jrburke] from comment #24)
> and the user timing stuff landing

The User Timing API will be implemented with bug 782751, and from what I understand :qDot was pretty interested in taking this on. He may be able to answer more definitively on that timeline. We can remove all the shims once that API lands.
Flags: needinfo?(kyle)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Redirecting to Gabriele.
Attachment #8533873 - Flags: review?(drs.bugzilla) → review?(gsvelto)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

r+ for email, by inspection
Attachment #8533873 - Flags: review?(jrburke) → review+
Attachment #8533873 - Flags: review?(m) → review+
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

TBH I'm not really a fan of the approach, I think we should just implement the gecko API in this case, but I'm fine with leaving my R+ for home screen/system app.

Please push on platform so we don't have to leave this shim in for too long.
Attachment #8533873 - Flags: review?(kgrandon) → review+
Just posted intent to implement to dev-platform/dev-webapi, and took implementation bug (Bug 782751).
Flags: needinfo?(kyle)
I am not entirely sure which part of the code I should be review here?
Flags: needinfo?(eperelman)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

LGTM for the dialer. I'd suggest in the future to split up a PR like this in multiple commits, one per app, to simplify review among other things. See this PR for instance in which I had to alter multiple apps for a similar purpose:

https://github.com/mozilla-b2g/gaia/pull/24894
Attachment #8533873 - Flags: review?(gsvelto) → review+
Hey Tim, could you review the bits for the FM Radio?
Flags: needinfo?(eperelman)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Rubberstamp if nothing breaks.
Attachment #8533873 - Flags: review?(timdream) → review+
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

I still don't understand why we need this before the platform is ready. I'm perfectly ok with the approach, I just don't think it's wise to do it now, using a polyfill. I don't see the benefits of this.

That said, there is no performance regression anymore, so feel free to land with my r+. Please don't pack things into usertiming.js in the future though.

Did somebody review your changes to usertiming?
Attachment #8533873 - Flags: review?(felash) → review+
Oh and BTW you need to rebase your Settings change, looks like everything changed there :)
(In reply to Julien Wajsberg [:julienw] from comment #36)
> I still don't understand why we need this before the platform is ready. I'm
> perfectly ok with the approach, I just don't think it's wise to do it now,
> using a polyfill. I don't see the benefits of this.

The reasoning behind the use of a polyfill is the usage of the new performance testing methodologies is blocked by not having this functionality. In order to keep advancing on developing the new performance infrastructure, we need this.

> Did somebody review your changes to usertiming?

Yes, :djf gave a look through it. Thanks!
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Music reviewed by :djf, Calendar and Usage coming in separate patches.
Attachment #8533873 - Flags: review?(gaye)
Attachment #8533873 - Flags: review?(dkuo)
Attachment #8533873 - Flags: review?(21)
Keywords: checkin-needed
Adding the new performance markers to the Calendar app.
Attachment #8537858 - Flags: review?(gaye)
Adding new performance markers to the Usage app.
Attachment #8537865 - Flags: review?(marina.rodriguez.iglesias)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Arthur, could you please re-review the settings changes. My rebase with the Settings refactor didn't go so well, so I'd like to make sure everything is kosher this time. Thanks!
Attachment #8533873 - Flags: review+ → review?(arthur.chen)
Comment on attachment 8533873 [details]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26679

Looks good! r=me.
Attachment #8533873 - Flags: review?(arthur.chen) → review+
Comment on attachment 8537865 [details] [review]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26852

Hi Eli,
LGTM and works fine on the device, please fix the unit test and land once TBPL is ok.
Best regards
Attachment #8537865 - Flags: review?(marina.rodriguez.iglesias) → review+
Comment on attachment 8538541 [details] [review]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26887

Carrying over r+ from:

kgrandon, mcav, francisco, gsvelto, timdream, arthur.chen, dflanagan, felash, wilsonpage, and jrburke.
Attachment #8538541 - Flags: review+
Anyone from Calendar that could review this would be appreciated. :)
Attachment #8537858 - Attachment is obsolete: true
Attachment #8537858 - Flags: review?(gaye)
Attachment #8538936 - Flags: review?(mmedeiros)
Attachment #8538936 - Flags: review?(kgrandon)
Attachment #8538936 - Flags: review?(gaye)
Eli - I see that this was backed out. When something is backed out please comment with the commit SHA and reason it was backed out. Why was it backed out in the first place, and what's changed about this patch?
Flags: needinfo?(eperelman)
It was backed out because I accidentally landed the patch for Calendar instead of Usage, which hadn't completed review yet, so I backed it out immediately. There is no difference in the other patch that you had seen, I just needed a new PR.
Flags: needinfo?(eperelman)
Comment on attachment 8538936 [details] [review]
Link to Github pull-request: https://github.com/mozilla-b2g/gaia/pull/26899

LGTM. changes only affects our `performance.js` script and are on the same locations that we dispatch the `moz-` events (so it looks correct)
Attachment #8538936 - Flags: review?(mmedeiros)
Attachment #8538936 - Flags: review?(kgrandon)
Attachment #8538936 - Flags: review?(gaye)
Attachment #8538936 - Flags: review+
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Keywords: leave-open
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.