Closed Bug 1145824 Opened 10 years ago Closed 10 years ago

Expose a getElapsedTime on nsIProfiler and allow getProfileData to filter by a start time

Categories

(Core :: Gecko Profiler, defect)

x86_64
Linux
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla40
Tracking Status
firefox40 --- fixed

People

(Reporter: shu, Assigned: jsantell)

References

Details

Attachments

(4 files, 11 obsolete files)

(deleted), patch
Details | Diff | Splinter Review
(deleted), patch
Details | Diff | Splinter Review
(deleted), patch
Details | Diff | Splinter Review
(deleted), patch
jsantell
: review+
Details | Diff | Splinter Review
Right now the frontend devtools is jumping through hoops to figure out when a currently running instance of the profiler started by dumping the entire profile and computing the elapsed time of the oldest profile. Please let's not make them do this.
s/oldest profile/oldest sample
Blocks: 1145738
Summary: Expose a scriptable getStartTime() method on nsIProfiler → Expose a getElapsedTime on nsIProfiler and allow getProfileData to filter by a start time
Attached patch Add getElapsedTime to nsIProfiler. (obsolete) (deleted) — Splinter Review
Attachment #8581011 - Flags: review?(mstange)
Attachment #8581012 - Flags: review?(mstange)
Attachment #8581013 - Attachment is obsolete: true
Attachment #8581013 - Flags: review?(jsantell)
Attachment #8581042 - Flags: review?(jsantell)
Attachment #8581042 - Flags: feedback?
Attachment #8581042 - Flags: feedback? → feedback?(vporof)
Oops, accidentally committed some debugging stuff.
Attachment #8581042 - Attachment is obsolete: true
Attachment #8581042 - Flags: review?(jsantell)
Attachment #8581042 - Flags: feedback?(vporof)
Attachment #8581043 - Flags: review?(jsantell)
Attachment #8581043 - Flags: feedback?(vporof)
Comment on attachment 8581043 [details] [diff] [review] Update the performance tool to use nsIProfiler's getElapsedTime and getProfileData's new filtering abilities. Review of attachment 8581043 [details] [diff] [review]: ----------------------------------------------------------------- ::: toolkit/devtools/server/actors/profiler.js @@ +80,5 @@ > > /** > * Stops the nsIProfiler module, if no other client is using it. > */ > onStopProfiler: function() { Oops, onStopProfiler is supposed to have gProfilingStartTime = 0 after nsIProfilerModule.StopProfiler().
What ever stops the profiler? I don't see anything actually calling requesting "stopProfiler" on the profiler actor.
Flags: needinfo?(vporof)
Jordan, could you test with these patches if the problem still happens?
Attached patch Fix tests. (obsolete) (deleted) — Splinter Review
I'm not sure how data-massaging-01 ever worked.
Attachment #8581072 - Flags: review?(jsantell)
Sorry for the review churn. This updated version removes gProfilingStartTime entirely. I left it in in the last version for no good reason.
Attachment #8581043 - Attachment is obsolete: true
Attachment #8581043 - Flags: review?(jsantell)
Attachment #8581043 - Flags: feedback?(vporof)
Attachment #8581248 - Flags: review?(jsantell)
Attachment #8581248 - Flags: feedback?(vporof)
Attachment #8581011 - Flags: review?(mstange) → review+
Comment on attachment 8581012 [details] [diff] [review] In nsProfiler, allow GetProfile and getProfileData to filter by a start time. Review of attachment 8581012 [details] [diff] [review]: ----------------------------------------------------------------- ::: tools/profiler/ProfileEntry.cpp @@ +274,5 @@ > mWriter.EndObject(); > } > }; > > +void ProfileBuffer::StreamSamplesToJSObject(JSStreamWriter& b, int aThreadId, float aSinceTime, please add a line break before "float"
Attachment #8581012 - Flags: review?(mstange) → review+
(In reply to Shu-yu Guo [:shu] from comment #8) > What ever stops the profiler? I don't see anything actually calling > requesting "stopProfiler" on the profiler actor. The only attempt to stop the profiler is on the backend, in the `disconnect` function in profiler.js. This is called as soon as a connection is closed, so when a toolbox is destroyed. The frontend never calls `stopProfiler` manually while the toolbox, because we can't guarantee that there are no other consumers of this actor (e.g. other toolboxes, other profilers etc.). For simultaneous recordings, we rely on `isActive` and the "current" time to filter a profile. It is not correct to simply count the number of calls to `startProfiler` and only actually stop the profiler when this reaches 0 (in `stopProfiler`), because `startProfiler` actually discards all the previously recorded data (basically throwing away the entire circular buffer). Therefore, we count the number of *connections* to the actor, and stop the profiler when all the connections close. This doesn't guard against someone unexpectedly stopping the profiler module itself (e.g. addons not using the profiler actor, but accessing the nsIProfiler module directly).
Flags: needinfo?(vporof)
(In reply to Victor Porof [:vporof][:vp] from comment #13) > > The frontend never calls `stopProfiler` manually while the toolbox, because Typo: "while the toolbox *is open*"
Comment on attachment 8581248 [details] [diff] [review] Update the performance tool to use nsIProfiler's getElapsedTime and getProfileData's new filtering abilities. Review of attachment 8581248 [details] [diff] [review]: ----------------------------------------------------------------- r- mainly because I think the use of gLastConsoleProfileStartTime is incorrect. r+ if I'm wrong. ::: browser/devtools/performance/modules/front.js @@ +266,5 @@ > * @return object > * A promise that is resolved once recording has stopped, > * with the profiler and memory data, along with all the end times. > */ > + stopRecording: Task.async(function*(startTime, options = {}) { Rename this to profilerStartTime and add some documentation above. Would like to clearly state *why* this is necessary. ::: toolkit/devtools/server/actors/profiler.js @@ +131,5 @@ > * } ... ] > * } ... ] > * } > + * > + * @param number startTime You and I know why startTime is needed, but contributors may not. Please add a line documenting its use. @@ +248,5 @@ > currentTime: 0 > }; > } > + > + gLastConsoleProfileStartTime = currentTime; I don't think this is correct. Suppose one does console.profile("foo"); console.profile("bar"); console.profileEnd("foo"); In the second case, the profile range is between when "bar" started and "foo" stopped. Am I misreading this? @@ -277,5 @@ > /** > - * Gets the time elapsed since the profiler was last started. > - * @return number > - */ > -function getElapsedTime() { I AM SO HAPPY TO SEE THIS NUKED.
Attachment #8581248 - Flags: review?(jsantell)
Attachment #8581248 - Flags: review-
Attachment #8581248 - Flags: feedback?(vporof)
Comment on attachment 8581248 [details] [diff] [review] Update the performance tool to use nsIProfiler's getElapsedTime and getProfileData's new filtering abilities. Review of attachment 8581248 [details] [diff] [review]: ----------------------------------------------------------------- ::: toolkit/devtools/server/actors/profiler.js @@ +248,5 @@ > currentTime: 0 > }; > } > + > + gLastConsoleProfileStartTime = currentTime; Should the profiler actor manage the console.profiles? This lets someone start up the profiler without all of the other actors, but with the new performance tool, a console profile is compromised of several actors (timeline, memory, profiler). If we have the profiler back end also manage it, we'll have duplicated, or worse, inconsistent logic. In the console.profile patch bug 1077464, the console profiles just listen to the event that a profile started/stopped via console with an optional label, and the perf front starts the profiler, and all other actors necessary. I think we should just have the profiler actor just listen and emit the console events, and make no other assumptions about it, unless there's another downside I'm missing, so that all profiler interaction goes through the performance front. If we wait to land this in Fx40, the console profile patch should work with the removal of this logic here.
Attachment #8581072 - Flags: review?(jsantell) → review+
(In reply to Victor Porof [:vporof][:vp] from comment #13) > > It is not correct to simply count the number of calls to `startProfiler` and > only actually stop the profiler when this reaches 0 (in `stopProfiler`), > because `startProfiler` actually discards all the previously recorded data > (basically throwing away the entire circular buffer). Therefore, we count > the number of *connections* to the actor, and stop the profiler when all the > connections close. > This was written under the assumption that the counting to `startProfiler` is done on the instance. However, if we count into a global variable, and the module global scope is always the same for all connections, then this should not be a problem. After discussing on IRC though, we concluded that it'll be even safer to move this logic on the nsIProfiler side. This will prevent us from accidentally breaking other consumers of the profiler which are not using the actor.
Assignee: nobody → jsantell
Depends on: 1147945
Jordan, what do you think I just land this now and leave the console stuff broken until the console patch lands?
Flags: needinfo?(jsantell)
I really don't want to rebase and reland bug 1077464 a fourth time -- its waiting on checkin needed (feel free to land it) -- that being said, we have many in progress profiler patches that are getting out of sync and out of hand, so if you land bug 1077464 (I'm AFK for a bit) and this passes try, let's land it as well
Flags: needinfo?(jsantell)
Attached file Add getElapsedTime to nsIProfiler. (obsolete) (deleted) —
Rebased. Carrying r=mstange.
Attachment #8581011 - Attachment is obsolete: true
Attachment #8593625 - Flags: review+
Rebased. Carrying r=mstange.
Attachment #8581012 - Attachment is obsolete: true
Attachment #8593626 - Flags: review+
Blocks: 1155535
So, working on getting this landed. Corrected victor's nits, and reaccessing the console.profile portions. The current patch would not work on correctly matching console.profiles together via the label, and would cause mismatches as the front currently handles that. Changes being implemented: * console events in profiler server ensure that the profiler is running so we do not lose samples, and send the correct "startTime" for that profile to the front. It no longer handles returning profiler data upon completion. The console.profile functionality is only in the profiler server to provide hooks, and only makes sense within the context of a devtools toolbox, so handling the piecing together of the actual model on the front is OK. Downside is -- there will be a slight delay from receiving the event until actually stopping. This isn't great, but having an "endTime" option filter on getProfileData would fix this, additionally, solve any delay/lag issues between front and server even in just a normal profile. Bug 1155535 for adding "endTime" to getProfileData * Adding a "traits" property to "getFeatures" for the profiler actor. To contrast with the SPS Profiler "features", "traits" describes features available on the actor, like "filterable" in this case, so we know whether or not to filter samples on the client.
Updating console.profileEnd to not actually fetch the samples fixes the issue where samples are fetched twice in console profiles.
Attached patch 1145824-filter-samples.patch (obsolete) (deleted) — Splinter Review
Got rid of most test changes -- this shouldn't change the front's interface at all. Added a test for backwards compatibility on older profiler versions. The rest is mentioned well in comment #22.
Attachment #8581072 - Attachment is obsolete: true
Attachment #8581248 - Attachment is obsolete: true
Attachment #8594145 - Flags: review?(nfitzgerald)
And this is not an objective, measured position, but this FEELS WAY FASTER!!! :D
No longer depends on: 1147945
Blocks: 1147945
Depends on: 1155897
Comment on attachment 8594145 [details] [diff] [review] 1145824-filter-samples.patch Review of attachment 8594145 [details] [diff] [review]: ----------------------------------------------------------------- r=me with below addressed ::: toolkit/devtools/server/actors/profiler.js @@ +55,5 @@ > + features: nsIProfilerModule.GetFeatures([]), > + traits: { > + // Whether or not `getProfile()` supports specifying a `startTime` > + // and `endTime` to filter out samples. > + filterable: true Why isn't this part of https://dxr.mozilla.org/mozilla-central/source/toolkit/devtools/server/actors/root.js#109-169 ? The way it is implemented here requires a second RDP round trip, when the frontend could just check the traits that are sent in the server's hello packet and there would be no extra round trip.
Attachment #8594145 - Flags: review?(nfitzgerald) → review+
Comment on attachment 8594145 [details] [diff] [review] 1145824-filter-samples.patch Review of attachment 8594145 [details] [diff] [review]: ----------------------------------------------------------------- Thanks, Nick! Actually the extra fetch to request the traits causes the perf connection init to be slightly longer, causing a lot of failures due to attempting to destroy perf connection before it's actually created in some tests (that do not have gDevTools.testing on) -- created bug 1155897 for this. ::: toolkit/devtools/server/actors/profiler.js @@ +55,5 @@ > + features: nsIProfilerModule.GetFeatures([]), > + traits: { > + // Whether or not `getProfile()` supports specifying a `startTime` > + // and `endTime` to filter out samples. > + filterable: true My thinking was that the root actor has a lot of traits, and this only affects profiler and not something useful on a toolbox level (blackboxing, memory allocations), but you're right, it does require an extra request. Depending on the future changes to SPS profiler, we may have a few of these little flags, and I just don't want to pollute the global traits for that. Ideally this would be on the ProfilerFront, defined on the server, as a static property, but the profiler is old school. I'll make this change, but maybe we can change the Profiler to be more in line with our newer actors and clean this up a bit
(In reply to Jordan Santell [:jsantell] [@jsantell] from comment #28) > My thinking was that the root actor has a lot of traits, and this only > affects profiler and not something useful on a toolbox level (blackboxing, > memory allocations), but you're right, it does require an extra request. > > Depending on the future changes to SPS profiler, we may have a few of these > little flags, and I just don't want to pollute the global traits for that. There are a ton of traits like this -- don't worry about it and just prefix the trait name with "profiler" or something if it makes sense. > Ideally this would be on the ProfilerFront, defined on the server, as a > static property, but the profiler is old school. Unless I misunderstand what you are suggesting, that's not possible. The ProfilerFront is in browser/ and is loaded by frontend code -- the server (in another process) can't define properties on it. You could define a getter on the ProfilerFront that just checks the hello packet's trait, though. That seems pretty convenient.
You're right -- I was thinking about our front's that had static methods (bug 1132208 for example) -- but these are just included on the client via loader, so it'd just get the client's version of traits anyway.
Attached patch 1145824-filter-samples.patch (obsolete) (deleted) — Splinter Review
Trying to clean up the tearing down didn't go as planned in bug 1155897 -- most tests do not wait for toolbox to finish being torn down. Readding the gDevTools.testing yield on start up for it to fix it hopefully. Not the cleanest, but it should hopefully work. Added gDevTools.testing to some tests. Moved profiler trait to root actor. https://treeherder.mozilla.org/#/jobs?repo=try&revision=353cdf6e9027
Attachment #8594145 - Attachment is obsolete: true
Blocks: 1152606
Attached patch 1145824-filter-samples.patch (deleted) — Splinter Review
Accidently removed the onGetFeatures method on profiler actor, woops. https://treeherder.mozilla.org/#/jobs?repo=try&revision=736f8523d1dd
Attachment #8597394 - Attachment is obsolete: true
No longer depends on: 1155897
Rebased.
Removing [fixed-in-fx-team] Shu, if your try tests pass the M-oth failure for just the platform code, let's land it -- reduces the problem area on the front end code.
Whiteboard: [fixed-in-fx-team]
Was causing m-oth timeouts.
Attachment #8597650 - Flags: review?(jsantell)
Comment on attachment 8597650 [details] [diff] [review] Reset dom.send_after_paint_to_content when toggling gDevTools.testing, as chrome tests need it. Review of attachment 8597650 [details] [diff] [review]: ----------------------------------------------------------------- There were some webide tests running in the mochitest-chrome suite, which had this pref never reset, causing all those lovely failures.
Attachment #8597650 - Flags: review?(jsantell) → review+
Attachment #8593626 - Attachment is obsolete: true
Attachment #8593626 - Attachment is patch: false
Attachment #8593625 - Attachment is obsolete: true
Attachment #8593625 - Attachment is patch: false
Pushed the 2 platform and 2 devtools patches to try with m-oth, in addition to the normal devtools suite: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6449e10ee066
Status: NEW → ASSIGNED
Whiteboard: [fixed-in-fx-team]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: