Closed
Bug 1348024
Opened 8 years ago
Closed 8 years ago
Make the profiler env vars MOZ_PROFILER_ENTRIES and MOZ_PROFILER_INTERVAL specific to startup
Categories
(Core :: Gecko Profiler, enhancement)
Core
Gecko Profiler
Tracking
()
RESOLVED
FIXED
mozilla55
Tracking | Status | |
---|---|---|
firefox55 | --- | fixed |
People
(Reporter: mstange, Assigned: n.nethercote)
References
Details
Attachments
(1 file, 1 obsolete file)
(deleted),
patch
|
mstange
:
review+
|
Details | Diff | Splinter Review |
Currently, these environment variables apply every time the profiler is started throughout the lifetime of the process, and they overwrite any value that was supplied to the arguments of nsIProfiler::StartProfiler / profiler_start.
However, these environment variables are only really needed for startup profiling. So I think we should rename them to MOZ_PROFILER_STARTUP_ENTRIES / MOZ_PROFILER_STARTUP_INTERVAL and only respect them if we start the profiler in profiler_init.
Assignee | ||
Comment 1•8 years ago
|
||
By "startup profiling" do you mean setting MOZ_PROFILER_STARTUP? I don't understand the various ways the profile can start up. When is startup profiling used? Does the profiler add-on use it?
Flags: needinfo?(mstange)
Reporter | ||
Comment 2•8 years ago
|
||
(In reply to Nicholas Nethercote [:njn] from comment #1)
> By "startup profiling" do you mean setting MOZ_PROFILER_STARTUP?
Yes, exactly.
> I don't understand the various ways the profile can start up. When is startup
> profiling used? Does the profiler add-on use it?
At the moment, startup profiling is only used when you manually set the MOZ_PROFILER_STARTUP environment variable when you launch Firefox from the command line. This was last done successfully in bug 1312373 comment 11.
The old add-on had a button that would restart Firefox with MOZ_PROFILER_STARTUP set, but the new add-on doesn't have such a button yet, see https://github.com/devtools-html/Gecko-Profiler-Addon/issues/31 .
When the add-on initializes, it also starts the profiler: https://github.com/devtools-html/Gecko-Profiler-Addon/blob/a23ac75241af1f1f06c0b625e199da6f4721e3fa/index.js#L224
It just calls nsIProfiler.startProfiler as usual. Add-on initialization happens much later during startup than profiler_init, though, so this automatic starting of the profiler is not very useful when you want to know what happens during early startup - you'll have to use MOZ_PROFILER_STARTUP for that.
Flags: needinfo?(mstange)
Assignee | ||
Comment 3•8 years ago
|
||
The patch also renames profiler_usage() as PrintUsageThenExit().
Attachment #8849811 -
Flags: review?(mstange)
Assignee | ||
Updated•8 years ago
|
Assignee: nobody → n.nethercote
Status: NEW → ASSIGNED
Assignee | ||
Comment 4•8 years ago
|
||
With this patch applied and the following env vars:
> MOZ_LOG="prof:3" MOZ_PROFILER_STARTUP= MOZ_PROFILER_STARTUP_INTERVAL=2 MOZ_PROFILER_STARTUP_ENTRIES=999999
Here's the output I get when I simply start the browser with the profiler
add-on installed.
> [Main Thread]: I/prof [12430] profiler_init
> [Main Thread]: I/prof [12430] - MOZ_PROFILER_STARTUP is set
> [Main Thread]: I/prof [12430] - MOZ_PROFILER_STARTUP_ENTRIES = 999999
> [Main Thread]: I/prof [12430] - MOZ_PROFILER_STARTUP_INTERVAL = 2
> [Main Thread]: I/prof [12430] locked_profiler_start
> [Main Thread]: I/prof [12430] - entries = 999999
> [Main Thread]: I/prof [12430] - interval = 2.00
> [Main Thread]: I/prof [12430] - feature = js
> [Main Thread]: I/prof [12430] - feature = leaf
> [Main Thread]: I/prof [12430] - feature = stackwalk
> [Main Thread]: I/prof [12430] - feature = threads
> [Main Thread]: I/prof [12430] - threads = GeckoMain
> [Main Thread]: I/prof [12430] - threads = Compositor
> [Main Thread]: I/prof [12481] profiler_init
> [Main Thread]: I/prof [12481] - MOZ_PROFILER_STARTUP is set
> [Main Thread]: I/prof [12481] - MOZ_PROFILER_STARTUP_ENTRIES = 999999
> [Main Thread]: I/prof [12481] - MOZ_PROFILER_STARTUP_INTERVAL = 2
> [Main Thread]: I/prof [12481] locked_profiler_start
> [Main Thread]: I/prof [12481] - entries = 999999
> [Main Thread]: I/prof [12481] - interval = 2.00
> [Main Thread]: I/prof [12481] - feature = js
> [Main Thread]: I/prof [12481] - feature = leaf
> [Main Thread]: I/prof [12481] - feature = stackwalk
> [Main Thread]: I/prof [12481] - feature = threads
> [Main Thread]: I/prof [12481] - threads = GeckoMain
> [Main Thread]: I/prof [12481] - threads = Compositor
> [Main Thread]: I/prof [12481] profiler_start <-- ???
> [Main Thread]: I/prof [12481] locked_profiler_stop
> [Main Thread]: I/prof [12481] locked_profiler_start
> [Main Thread]: I/prof [12481] - entries = 999999
> [Main Thread]: I/prof [12481] - interval = 2.00
> [Main Thread]: I/prof [12481] - feature = js
> [Main Thread]: I/prof [12481] - feature = leaf
> [Main Thread]: I/prof [12481] - feature = stackwalk
> [Main Thread]: I/prof [12481] - feature = threads
> [Main Thread]: I/prof [12481] - threads = GeckoMain
> [Main Thread]: I/prof [12481] - threads = Compositor
It looks reasonable to start with -- two profiler_init() calls, one for the
parent (12430), one for the child (12481). Both of them use the entries and
interval values from the env vars as expected.
But then the child process calls profiler_start() again, which is surprising,
and doesn't happen when MOZ_PROFILER_STARTUP is undefined. This makes the
profiler stop and restart.
Furthermore, entries and interval are 999999 and 2.00 on this restart, but
profiler_init() is not involved, so they can't have been read from the env
vars. This suggests that the profiler add-on obtained the prior start
parameters and restarted with them.
mstange, does this look like you'd expect?
Flags: needinfo?(mstange)
Assignee | ||
Comment 5•8 years ago
|
||
Comment on attachment 8849811 [details] [diff] [review]
Make the env vars MOZ_PROFILER_{ENTRIES,INTERVAL} specific to startup
Review of attachment 8849811 [details] [diff] [review]:
-----------------------------------------------------------------
Hmm, I need to fix up some Android and Talos stuff.
Attachment #8849811 -
Flags: review?(mstange)
Reporter | ||
Comment 6•8 years ago
|
||
The unexpected profiler_start call is triggered by this: http://searchfox.org/mozilla-central/source/dom/ipc/ContentParent.cpp#1329
We're launching a child process while the parent process is being profiled, so we tell the new process that it should also profile itself.
Not sure what to do about the unfortunate clearing of the buffer.
Flags: needinfo?(mstange)
Reporter | ||
Comment 7•8 years ago
|
||
Hmm, so we have two ways to start the profiler at the beginning of a content process, and they conflict with each other. Maybe we can unify them. For example, instead of using SendStartProfiler, we could do the following: When launching a child process, if the profiler is running in the parent, launch the child process with the appropriate MOZ_PROFILER_STARTUP* env variables. And if the profiler is not running in the parent, unset any MOZ_PROFILER_STARTUP* env vars for the new child process.
Blindly inheriting the env vars into child processes is not a good idea anyway. If you use startup profiling, you usually wait for startup to finish, grab a profile, and stop the profiler. But if a new child process is launched after this point, with the current setup, it will enable startup profiling for itself even though Firefox startup is already over.
Assignee | ||
Comment 8•8 years ago
|
||
Thank you for the explanation. This is clearly a pre-existing problem with MOZ_PROFILER_STARTUP and can be fixed in a follow-up.
Reporter | ||
Comment 9•8 years ago
|
||
Absolutely.
Assignee | ||
Comment 10•8 years ago
|
||
The patch also renames profiler_usage() as PrintUsageThenExit().
Attachment #8850290 -
Flags: review?(mstange)
Assignee | ||
Updated•8 years ago
|
Attachment #8849811 -
Attachment is obsolete: true
Reporter | ||
Comment 11•8 years ago
|
||
Comment on attachment 8850290 [details] [diff] [review]
Make the env vars MOZ_PROFILER_{ENTRIES,INTERVAL} specific to startup
Review of attachment 8850290 [details] [diff] [review]:
-----------------------------------------------------------------
Thanks! Sorry for the delay.
::: tools/profiler/core/platform-linux-android.cpp
@@ +556,5 @@
> // So we free them later, but we don't want to change the const char**
> // declaration in profiler_start. Annoying but ok for now.
> const char* threadNames[10];
> const char* features[10];
> const char* profilerConfigFile = "/data/local/tmp/profiler.options";
Thanks for putting this code under my nose again. It's not needed, I've filed bug 1351946.
Attachment #8850290 -
Flags: review?(mstange) → review+
Assignee | ||
Comment 12•8 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/c3653faaac8aad50623a0ed57bcc77d8a5bdc7f7
Bug 1348024 - Make the env vars MOZ_PROFILER_{ENTRIES,INTERVAL} specific to startup. r=mstange.
Comment 13•8 years ago
|
||
bugherder |
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
You need to log in
before you can comment on or make changes to this bug.
Description
•