Closed Bug 886555 Opened 7 years ago Closed 6 years ago

metrofx: profiler ties all samples to the Startup::XRE_Main symbol.

Categories

(DevTools :: Performance Tools (Profiler/Timeline), defect, P1)

x86_64
Windows 8
defect

Tracking

(Not tracked)

RESOLVED FIXED
Firefox 28

People

(Reporter: ally, Unassigned)

References

Details

Attachments

(5 files)

The profiler in firefox classic desktop devtools & the one at http://people.mozilla.com/~bgirard/cleopatra/# are choking on the profiler data produced by metrofx. 

On the web frontend the site/browser become unresponsive with an error about unresponsive script of cleopatra/js/histogram.js:250

On the classic fx desktop devtools panel it produces the profiler ui, but devoid of data.

Attached are screen shots of the issue and the profiler json.
hi ally,

Could you attach a copy of the profile data so we can take a look at it?
Priority: -- → P1
OK, seems like I can reproduce this failure on a Mac. Taking my computer home, will try to figure this out over the weekend.
This happens because metrofx returns profile data in the wrong format. We expect this:

  {
    "libs": "...",
    "meta": { ... },
    "threads": [ { ... },.. ]
  }

And metrofx returns (what seems to be a multi-threaded version?) this:

  {
    "profile": {
      "libs": "...",
      "meta": { ... },
      "threads": [ { ... },.. ]
     },
     "from": "..."
  }

After I remove that extra "profile" wrapper my Nightly shows this: http://cl.ly/image/1a3R0i2N0L0h Looking at the JSON data this output seems to be correct, even if strange.
False alarm, it was an issue with bug 828046 I'm using for testing.
So the profiler UI works fine. The problem was that our backend on metrofx tied all samples to one location: Startup::XRE_Main. And, since it's not a JS symbol, we didn't show it by default. Which meant that the UI had nothing to show at all.

Bug 833495 introduced an option to display platform data and if you enable it you can see the output similar to my screenshot in comment 8. (confirmed both on my Mac and Ally's Metro)

Now the question is, why do we tie everything to one location? CCing BenWa on that.
Summary: profiler choking on profile from metrofx → metrofx: profiler ties all samples to the Startup::XRE_Main symbol.
When we take a sample we record all the profiler_label which are active. Startup::XRE_Main is activated at the start of gecko so all samples go through this code. This is expected behavior. If you catch execution while other profiler_label are active then it will be in the profile.
(In reply to Benoit Girard (:BenWa) from comment #12)
> Try hardcoding this value to true:
> http://mxr.mozilla.org/mozilla-central/source/tools/profiler/TableTicker.h#54

Turns up nothing. The only difference in either error console (devtools.errorconsole.enabled is true) are these, which appear on the classicfx side:

[14:29:53.594] XUL box for span element contained an inline #text child, forcing all its children to be wrapped in a block. @ resource://app/modules/devtools/SideMenuWidget.jsm:578
--
[14:30:05.569] Use of Mutation Events is deprecated. Use MutationObserver instead. @ chrome://browser/content/devtools/orion.js:3408
--
[14:30:30.041] TypeError: frameData.scriptLocation is undefined @ chrome://browser/content/devtools/profiler/cleopatra/js/ui.js:174

I doubt these have any relevance to this bug.
What should we do next?
Flags: needinfo?(bgirard)
(In reply to :Ally Naaktgeboren from comment #14)
> What should we do next?

I've got a metro machine compiling. I'll see what I can do.
Flags: needinfo?(bgirard)
Alright I was able to get the profiler to work on metro. Here's the full steps (no patches needed):

1) Run metro from a nightly build
2) Turn on 'devtools.debugger.remote-enabled;true'
3) Restart the metro browser - It is ready to be profiled
4) Run desktop nightly in a different profile
5) Install the profiler extension from: https://github.com/bgirard/Gecko-Profiler-Addon/raw/master/geckoprofiler.xpi
6) Make sure 'stackwalk' is enabled
7) Select TCP, hit connect, hit analyze
8) Wait a few seconds for the profile to serialize over the write (perhaps we can optimize this)
9) Note that currently we're having issues with the symbol server so you will have to wait longer for it to timeout until its fixed
10) The profile should open, if the symbol server is down you'll get addresses like this: http://people.mozilla.com/~bgirard/cleopatra/#report=5a5ccddf461ae64e2bdee59b025d911a0baa179c

Note I did notice that the profiler can deadlock the browser on windows 8. See should investigate that in a different bug.
Have the steps in comment 16 worked for you?
So I followed the instructions in comment 16 and I get a profile, but it's showing 100% of time spent in ZwWaitForMultipleObjects, basically showing Firefox is idle. It only shows the GeckoMain thread and clicking on the "Multi-Thread" checkbox in the profiler settings doesn't do anything (the checkbox remains unchecked).

I also tried using a local Metro build with a local symbolication server as explained at https://developer.mozilla.org/en-US/docs/Performance/Profiling_with_the_Built-in_Profiler_and_Local_Symbols_on_Windows and got the same results there (100% of time spent in ZwWaitForMultipleObjects).

These are the two profiles I saved from my Nightly and local build, respectively:
http://people.mozilla.org/~bgirard/cleopatra/#report=806f578d9f1e940ee822dbc817d14eb866b18517
http://people.mozilla.org/~bgirard/cleopatra/#report=e263f861ad9a752e68624144ea3954add38e152e
Also I'm fairly sure I'm getting all the right pieces hooked up to each other, because every time I "Start" the "desktop" Fx instance's gecko profiler I have to accept the incoming connection in the "metro" instance. I also checked about:buildconfig to make sure I was running the right instances where I expected to be, and when I grabbed a profile of my local build without the local symbolication server running the profile had just addresses rather than symbol names for the XRE symbols.
(In reply to Kartikaya Gupta (email:kats@mozilla.com) from comment #18)
> So I followed the instructions in comment 16 and I get a profile, but it's
> showing 100% of time spent in ZwWaitForMultipleObjects, basically showing
> Firefox is idle. It only shows the GeckoMain thread and clicking on the
> "Multi-Thread" checkbox in the profiler settings doesn't do anything (the
> checkbox remains unchecked).
> 
> I also tried using a local Metro build with a local symbolication server as
> explained at
> https://developer.mozilla.org/en-US/docs/Performance/
> Profiling_with_the_Built-in_Profiler_and_Local_Symbols_on_Windows and got
> the same results there (100% of time spent in ZwWaitForMultipleObjects).
> 
> These are the two profiles I saved from my Nightly and local build,
> respectively:
> http://people.mozilla.org/~bgirard/cleopatra/
> #report=806f578d9f1e940ee822dbc817d14eb866b18517
> http://people.mozilla.org/~bgirard/cleopatra/
> #report=e263f861ad9a752e68624144ea3954add38e152e

Looks like the profiler isn't picking up the right thread. Metro's gecko thread is created after the main() thread drops down into Windows::ApplicationModel::Core::CoreApplicationFactory::Run(). Is there some way to switch profiling threads? Maybe even through an added line of code?
(In reply to Jim Mathies [:jimm] from comment #20)
> Looks like the profiler isn't picking up the right thread. Metro's gecko
> thread is created after the main() thread drops down into
> Windows::ApplicationModel::Core::CoreApplicationFactory::Run(). Is there
> some way to switch profiling threads? Maybe even through an added line of
> code?

I guess this wouldn't help much if you were interested in profiling the compositor thread though. Seems like there should be a way to switch threads in the browser view that displays results.
Alright looks like we need to register the main metro thread as well.
No longer blocks: 927121
(In reply to Benoit Girard (:BenWa) from comment #22)
> Alright looks like we need to register the main metro thread as well.

How do you go about doing that?
I think kats is going to handle it. But we need to add these calls when the thread is started and ended:
http://mxr.mozilla.org/mozilla-central/source/tools/profiler/GeckoProfiler.h#162

Ideally for metro the main content thread would still be called 'GeckoMain' since that threads is treated differently. But right now the profiler assumes that the thread that calls profiler_init is the GeckoMain thread so we'd have to break this assumption. This is only important so higher level features like bug 918825 will work on metro, we could punt on that.
I filed bug 927979 for registering the gecko thread on Metro. Note that I don't plan on working on it right away since I was able to get a useful enough profile to unblock me on bug 927121.
(In reply to Benoit Girard (:BenWa) from comment #16)
> Alright I was able to get the profiler to work on metro. Here's the full
> steps (no patches needed):
> 
> 1) Run metro from a nightly build
> 2) Turn on 'devtools.debugger.remote-enabled;true'
> 3) Restart the metro browser - It is ready to be profiled
> 4) Run desktop nightly in a different profile
> 5) Install the profiler extension from:
> https://github.com/bgirard/Gecko-Profiler-Addon/raw/master/geckoprofiler.xpi
> 6) Make sure 'stackwalk' is enabled
> 7) Select TCP, hit connect, hit analyze
> 8) Wait a few seconds for the profile to serialize over the write (perhaps
> we can optimize this)
> 9) Note that currently we're having issues with the symbol server so you
> will have to wait longer for it to timeout until its fixed
> 10) The profile should open, if the symbol server is down you'll get
> addresses like this:
> http://people.mozilla.com/~bgirard/cleopatra/
> #report=5a5ccddf461ae64e2bdee59b025d911a0baa179c
> 
> Note I did notice that the profiler can deadlock the browser on windows 8.
> See should investigate that in a different bug.

I'm not having much luck here. For remote connections they never seem to connect. Both machines have the firewall disabled. Error console didn't display anything.

For a local profile, in settings via the toolbar button, Stackwalk won't hold a checkmark. I was able to get connected to the local metro browser (it prompted) despite this, but I can't seem to get any results to display. Ctrl-shift-o brings up a profile tab that display an error I'll post in a sec.
The error is:

Error in worker: Exception: TypeError: threads[0] is undefined (http://people.mozilla.org/~bgirard/cleopatra/js/parserWorker.js:860)
(In reply to Jim Mathies [:jimm] from comment #27)
> The error is:
> 
> Error in worker: Exception: TypeError: threads[0] is undefined
> (http://people.mozilla.org/~bgirard/cleopatra/js/parserWorker.js:860)

I managed to get two things fixed - the above ever still happens, but if you click on the profile entry on the left triggering a reload, the profile loads up properly.

For remote debugging, make sure devtool.debugger.force-local is set to false on both machines. Also, when you flip this on win8, you'll likely get a firewall warning on the *desktop*, which you have to flip over to and approve.
Closing this out, I think we've sorted out all the issues and can now profile metrofx. I'll get our wiki updated with the latest info.

https://wiki.mozilla.org/Firefox/Windows_8_Integration#Using_Devtools
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 28
Hi, I tried this profiler mentioned in 
http://mikeconley.ca/blog/2012/06/15/gecko-profiler-now-works-in-thunderbird-daily/
with the current production thunderbird (24.2.0)  under windows7 (64-bit).
(This link was mentioned
in https://bugzilla.mozilla.org/show_bug.cgi?id=558528#c6
where the buffer size ought to be enlarged to reduce network
I/O overhead.)

And I got the same error reported when I enabled the profiler and
dumped the profile.

Error in worker: Exception: TypeError: threads[0] is undefined (http://people.mozilla.org/~bgirard/cleopatra/js/parserWorker.js:860

Just noticed this bugzilla entry, and so I am reporting this. (Maybe this should be fixed in Firefox 28 as mentioned above.)

BTW,
I noticed that disbling the profiler *from the addon manager*, and re-enabled it
as an addon created TWO copies of "disabled dump profile" messages in the
lower pane of the TB window, but I will investigate this more and report a bugzilla if it
is reproducible. Also, after the installation of profiler, I don't seem to see the icon on the
lower-upper corner for invoking MENU any more. (But this may be expected since we have to wait for 
firefox 28 for correct operation?)


TIA
(In reply to ISHIKAWA, Chiaki from comment #30)
> Hi, I tried this profiler mentioned in 
> http://mikeconley.ca/blog/2012/06/15/gecko-profiler-now-works-in-thunderbird-
> daily/
> with the current production thunderbird (24.2.0)  under windows7 (64-bit).
> (This link was mentioned
> in https://bugzilla.mozilla.org/show_bug.cgi?id=558528#c6
> where the buffer size ought to be enlarged to reduce network
> I/O overhead.)
> 
> And I got the same error reported when I enabled the profiler and
> dumped the profile.
> 
> Error in worker: Exception: TypeError: threads[0] is undefined
> (http://people.mozilla.org/~bgirard/cleopatra/js/parserWorker.js:860
> 
> Just noticed this bugzilla entry, and so I am reporting this. (Maybe this
> should be fixed in Firefox 28 as mentioned above.)
> 
> BTW,
> I noticed that disbling the profiler *from the addon manager*, and
> re-enabled it
> as an addon created TWO copies of "disabled dump profile" messages in the
> lower pane of the TB window, but I will investigate this more and report a
> bugzilla if it
> is reproducible. Also, after the installation of profiler, I don't seem to
> see the icon on the
> lower-upper corner for invoking MENU any more. (But this may be expected
> since we have to wait for 
> firefox 28 for correct operation?)
> 
> 
> TIA

You should file a new bug for that.
> You should file a new bug for that.

Thanks for your comment. I will do so once the new year holiday is over.

TIA
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.