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)

enhancement
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla55
Tracking Status
firefox55 --- fixed

People

(Reporter: mstange, Assigned: n.nethercote)

References

Details

Attachments

(1 file, 1 obsolete file)

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.
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)
(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)
The patch also renames profiler_usage() as PrintUsageThenExit().
Attachment #8849811 - Flags: review?(mstange)
Assignee: nobody → n.nethercote
Status: NEW → ASSIGNED
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)
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)
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)
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.
Thank you for the explanation. This is clearly a pre-existing problem with MOZ_PROFILER_STARTUP and can be fixed in a follow-up.
Absolutely.
The patch also renames profiler_usage() as PrintUsageThenExit().
Attachment #8850290 - Flags: review?(mstange)
Attachment #8849811 - Attachment is obsolete: true
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+
https://hg.mozilla.org/integration/mozilla-inbound/rev/c3653faaac8aad50623a0ed57bcc77d8a5bdc7f7 Bug 1348024 - Make the env vars MOZ_PROFILER_{ENTRIES,INTERVAL} specific to startup. r=mstange.
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.

Attachment

General

Created:
Updated:
Size: