809317 - Add SAMPLER_PRINT_LOCATION

Status: RESOLVED WONTFIX

(Core :: Gecko Profiler, defect)

Description

[Benoit Girard (:BenWa)]

Attachment: Part 1: Provide a pseudo stack implementation

I've been wanting a function such as SAMPLER_PRINT_LOCATION for debugging for quite a while. The usage is 'give me as much information about how we got here as possible' and can be useful for example to put in an object's constructor/destructors o trace its usage.

In the long term I want to evolve this support return the stack in a ExecutionStack structure that later we will be able to collect during a page mutation and forward to layout and painting. During the painting we will be able to associate that this paint was (in part) caused by this style change.

More generally this is the first step to support showing what caused an async execution.

Here's a sample of that I have so far:

Backtrace:
  (root)
  Startup::XRE_Main
  Events::ProcessGeckoEvents
  widget::ChildView::drawRect
  Paint::PresShell::Paint

Comment 1

[Benoit Girard (:BenWa)]

Attachment: Part 2: Support stackwalking

Comment 2

[Benoit Girard (:BenWa)]

Sample with part 2, notice a few bad frames (CMMFRandTemplate) and no de-mangling:


  CMMFRandTemplate
  start
  main
  _ZL7do_mainiPPc
  XRE_main
  Startup::XRE_Main
  CMMFRandTemplate
  _ZN7XREMain8XRE_mainEiPPcPK12nsXREAppData
  _ZN7XREMain11XRE_mainRunEv
  _ZN12nsAppStartup3RunEv
  _ZN10nsAppShell3RunEv
  -[NSApplication run]
  -[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
  -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
  _DPSNextEvent
  BlockUntilNextEventMatchingListInMode
  ReceiveNextEventCommon
  RunCurrentEventLoopInMode
  CFRunLoopRunSpecific
  __CFRunLoopRun
  __CFRunLoopDoObservers
  __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__
  __83-[NSWindow _postWindowNeedsDisplayOrLayoutOrUpdateConstraintsUnlessPostingDisabled]_block_invoke_01208
  _handleWindowNeedsDisplayOrLayoutOrUpdateConstraints
  -[NSView displayIfNeeded]
  -[NSView _displayRectIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:]
  -[NSThemeFrame _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
  -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
  -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
  -[NSView _recursiveDisplayRectIfNeededIgnoringOpacity:isVisibleRect:rectIsVisibleRectForView:topView:]
  -[NSView _drawRect:clip:]
  -[ChildView drawRect:]
  widget::ChildView::drawRect
  CMMFRandTemplate
  -[ChildView drawRect:inContext:alternate:]
  _ZN11nsChildView11PaintWindowE11nsIntRegionb
  _ZThn112_N6nsView11PaintWindowEP9nsIWidget11nsIntRegionj
  _ZN6nsView11PaintWindowEP9nsIWidget11nsIntRegionj
  _ZN13nsViewManager11PaintWindowEP9nsIWidget11nsIntRegionj
  _ZN13nsViewManager7RefreshEP6nsViewRK11nsIntRegionb
  Paint::PresShell::Paint
  CMMFRandTemplate
  _ZN9PresShell5PaintEP7nsIViewRK8nsRegionj
  _ZN7mozilla6layers15LayerManagerOGL19EndEmptyTransactionENS0_12LayerManager19EndTransactionFlagsE
  _ZN7mozilla6layers15LayerManagerOGL14EndTransactionEPFvPNS0_11ThebesLayerEP10gfxContextRK11nsIntRegionS8_PvES9_NS0_12LayerManager19EndTransactionFlagsE
  _ZN7mozilla6layers15LayerManagerOGL6RenderEv

Comment 3

[Benoit Girard (:BenWa)]

Comment on attachment 679047 [details] [diff] [review]
Part 2: Support stackwalking

Review of attachment 679047 [details] [diff] [review]:
-----------------------------------------------------------------

::: tools/profiler/TableTicker.cpp
@@ +1286,1 @@
>    doSampleStackTrace(stack, threadProfile, NULL);

This is missing 'ThreadProfile threadProfile(1000, stack);'

Comment 4

[(no longer active)]

Comment on attachment 679031 [details] [diff] [review]
Part 1: Provide a pseudo stack implementation

Review of attachment 679031 [details] [diff] [review]:
-----------------------------------------------------------------

::: tools/profiler/TableTicker.cpp
@@ +277,5 @@
>    }
>  
>    friend std::ostream& operator<<(std::ostream& stream, const ThreadProfile& profile);
>  
> +  void IterateTags(void callback(const ProfileEntry& entry, const char* tagStringData))

void (*callback)(...)

Even better: typedefs!

@@ +278,5 @@
>  
>    friend std::ostream& operator<<(std::ostream& stream, const ThreadProfile& profile);
>  
> +  void IterateTags(void callback(const ProfileEntry& entry, const char* tagStringData))
> +  {

Please add MOZ_ASSERT(callback) as a sanity check.

@@ +283,5 @@
> +    int readPos = mReadPos;
> +    while (readPos != mLastFlushPos) {
> +      // Number of tag consumed
> +      int incBy = 1;
> +      ProfileEntry entry = mEntries[readPos];

Nit: use a reference please.

@@ +1220,5 @@
> +void print_callback(const ProfileEntry& entry, const char* tagStringData) {
> +  switch (entry.mTagName) {
> +    case 's':
> +    case 'c':
> +      printf("  %s\n", tagStringData);

Send this stuff to stderr, please.

@@ +1231,5 @@
> +    mozilla_sampler_init();
> +
> +  ProfileStack *stack = tlsStack.get();
> +  if (!stack) {
> +    ASSERT(false);

MOZ_ASSERT.

@@ +1240,5 @@
> +  doSampleStackTrace(stack, threadProfile, NULL);
> +
> +  threadProfile.flush();
> +
> +  printf("Backtrace:\n");

Here too.

Comment 5

[(no longer active)]

Comment on attachment 679047 [details] [diff] [review]
Part 2: Support stackwalking

Review of attachment 679047 [details] [diff] [review]:
-----------------------------------------------------------------

r=me on the condition that you blog about this.  ;-)

::: tools/profiler/TableTicker.cpp
@@ +1236,5 @@
>  void print_callback(const ProfileEntry& entry, const char* tagStringData) {
>    switch (entry.mTagName) {
>      case 's':
>      case 'c':
>        printf("  %s\n", tagStringData);

You're missing a break.  Is that intentional?

@@ +1240,5 @@
>        printf("  %s\n", tagStringData);
> +    case 'l':
> +      char tagBuff[1024];
> +      unsigned long long pc = (unsigned long long)(uintptr_t)entry.mTagPtr;
> +      snprintf(tagBuff, DYNAMIC_MAX_STRING, "%#llx", pc);

Hmm, try printf-ing all this at the same time, no need to do it twice.

@@ +1246,5 @@
> +      NS_DescribeCodeAddress((void*)pc, &details);
> +      if (details.function) {
> +        printf("  %s\n", details.function);
> +      } else {
> +        printf("  %s\n", tagBuff);

stderr

@@ +1276,5 @@
> +#endif
> +
> +  TickSample sample;
> +  sample.fp = (unsigned char*)bp;
> +  sample.pc = NULL;

Nit: nullptr.

Comment 6

[Benoit Girard (:BenWa)]

https://tbpl.mozilla.org/?tree=Try&rev=fc3d1a83e513

Comment 7

[Benoit Girard (:BenWa)]

Attachment: patch

Going to land part 1, I want to send part 2 through try.

Comment 8

[Benoit Girard (:BenWa)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/f74e05b76740

Comment 9

[Benoit Girard (:BenWa)]

https://tbpl.mozilla.org/?tree=Try&rev=d8eb520a30ca

Comment 10

[Benoit Girard (:BenWa)]

Attachment: Part 2: Support stackwalking

Waiting on try run to land.

Comment 11

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/f74e05b76740

Comment 12

[Benoit Girard (:BenWa)]

Attachment: Part 2: Support stackwalking

rebase

Comment 13

[Benoit Girard (:BenWa)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/b5c19fdea86e

Comment 14

[Ed Morley [:emorley]]

Backed out for MSVC bustage:
e:/builds/moz2_slave/m-in-w32/build/tools/profiler/TableTicker.cpp(834) : error C3861: 'GetThreadHandle': identifier not found
e:/builds/moz2_slave/m-in-w32/build/tools/profiler/TableTicker.cpp(834) : error C3861: 'platform_data': identifier not found
e:/builds/moz2_slave/m-in-w32/build/tools/profiler/TableTicker.cpp(883) : error C2664: 'doMergeBacktrace' : cannot convert parameter 3 from 'uintptr_t' to 'void *'
e:/builds/moz2_slave/m-in-w32/build/tools/profiler/TableTicker.cpp(1318) : error C3861: '__builtin_frame_address': identifier not found 
https://tbpl.mozilla.org/php/getParsedLog.php?id=17645063&tree=Mozilla-Inbound

https://hg.mozilla.org/integration/mozilla-inbound/rev/76322fb13033

Comment 15

[Benoit Girard (:BenWa)]

https://tbpl.mozilla.org/?tree=Try&rev=ff1cb49c507d

Comment 16

[Benoit Girard (:BenWa)]

https://tbpl.mozilla.org/?tree=Try&rev=86924830a030

Comment 17

[Benoit Girard (:BenWa)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/14d25f6b938e

Comment 18

[Ed Morley [:emorley]]

Backed out for bustage, eg:
https://tbpl.mozilla.org/php/getParsedLog.php?id=17834284&tree=Mozilla-Inbound

https://hg.mozilla.org/integration/mozilla-inbound/rev/1545ae660f81

Comment 19

[Benoit Girard (:BenWa)]

*sigh*. I got the patch from my try run but it's not identical. I got mixed up somehow.

Comment 20

[Nickolay_Ponomarev]

Note for posterity: the code from part 1 was also removed in bug 1135236.

Comment 21

[Benoit Girard (:BenWa)]

I don't plan on implementing this anymore.