Stack sampling profiler: re-enable stack collection for stacks terminated by leaf functions

Stack sampling profiler: re-enable stack collection for stacks terminated by leaf functions

Collect the 5% of leaf-terminated stacks that we're currently missing.
Avoids crashes we saw previously on unwinding frames in injected third
party modules with functions not adhering to the Microsoft x64 calling
conventions, by blacklisting leaf unwinding for these modules when we
first see a bad frame.

With this change there's still a very small possibility of crashing if a
stack happens to start with one of the bad third party functions.  This
change will allow us to collect crash data on this case and inform a
decision about appropriate heuristics to deal with it.

BUG=516402
Committed: https://crrev.com/863f84165da958298516064732d4d5b62ad7eb59
Cr-Commit-Position: refs/heads/master@{#345012}

[Mike Wittman, 2015-08-03 19:57:30]

wittman@chromium.org changed reviewers:
+ zturner@chromium.org

[Mike Wittman, 2015-08-03 19:57:31]

Hi Zach, can you take a look at this before I send it on to Carlos?

[zturner, 2015-08-05 17:05:55]

lgtm.  Seems ok to me, but you might want multiple opinions given the complexity

[Mike Wittman, 2015-08-05 22:07:07]

wittman@chromium.org changed reviewers:
+ thakis@chromium.org

[Mike Wittman, 2015-08-05 22:07:07]

Hi Nico, would you be willing to review this in the absence of cpu@?

[Nico, 2015-08-15 01:44:18]

I think landing this is generally fine. It's somewhat complex, but it's limited
to a single file.

Two points:
1. I'm not sure if the blacklisting adds much (see below)
2. Since this is tricky code, is there a way to test it?

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
File base/profiler/native_stack_sampler_win.cc (right):

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:55: const void*
pending_blacklisted_module_;
I found it a bit confusing that this ephemeral value is a member on this class.

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:134: // on the stack. This happens in
about 5% of observed stacks and can
This seems surprisingly high to me.

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:146: // We blacklist the module as
untrustable for unwinding if we encounter a
Is this blacklisting useful? You're expecting some amount of crashes if case 2
happens at the top (right?), so this only helps for 3rd-party modules that have
invalid abi stuff but never have any leaf functions while sampling. That seems
not super useful to me – can you motivate why this blacklisting is useful a bit
more?

[Mike Wittman, 2015-08-16 00:54:12]

Thanks for the review.

On 2015/08/15 01:44:18, Nico (hiding) wrote:
> I think landing this is generally fine. It's somewhat complex, but it's
limited
> to a single file.
> 
> Two points:
> 1. I'm not sure if the blacklisting adds much (see below)

Response below.

> 2. Since this is tricky code, is there a way to test it?

I didn't immediately see where to put a good seam for testing without awkwardly
splitting up the logic. I'll flesh out some options and see if there's a
feasible middle ground.

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
File base/profiler/native_stack_sampler_win.cc (right):

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:55: const void*
pending_blacklisted_module_;
On 2015/08/15 01:44:18, Nico (hiding) wrote:
> I found it a bit confusing that this ephemeral value is a member on this
class.

I suppose we could treat this as an out argument of RecordStack instead. Let me
see how things shake out with the changes to improve testability.

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:134: // on the stack. This happens in
about 5% of observed stacks and can
On 2015/08/15 01:44:18, Nico (hiding) wrote:
> This seems surprisingly high to me.

That's the rough average I saw profiling startups on a local build. I didn't
look into what the leaf functions were.

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:146: // We blacklist the module as
untrustable for unwinding if we encounter a
On 2015/08/15 01:44:18, Nico (hiding) wrote:
> Is this blacklisting useful? You're expecting some amount of crashes if case 2
> happens at the top (right?)

That's correct, but the blacklisting should substantially mitigate the frequency
of these crashes.

> ... so this only helps for 3rd-party modules that have
> invalid abi stuff but never have any leaf functions while sampling.

No, the blacklisting makes it OK to encounter case 2 functions in these modules
at the top of the stack while sampling, *if* our first encounter of a case 2
function in the module is in a frame below the top of the stack. When that
happens we know the function is bad and record the module in the blacklist.
If/when we later encounter any function in the module at the top of the stack,
we assume it might be case 2 and don't continue the stack unwinding.

Where the blacklist doesn't help is if our first encounter of a case 2 function
in a module is at the top frame in the stack. Then, we don't know any better, so
pop RSP to get the return address, and likely crash.

> That seems
> not super useful to me – can you motivate why this blacklisting is useful a
bit
> more?

The last time we enabled this functionality we blindly popped RSP whenever we
didn't get unwind information, even if we weren't at the top of the stack. We
saw 184 crashes, all apparently due to either an injected third party module
that was hooking Win32 or that had set its own WndProc. The vast majority were
obviously due to case 2 in frames below the top of the stack. These crashes
would be fixed by this change. 

Of the other crashes, it's not clear how many were case 2 at the top of the
stack vs. just being difficult to tell what was going on.

Crash data from this change should make clear the frequency of encountering case
2 at the top of the stack as the first encounter of a case 2 function in a
module. This will inform a decision about how to deal with this scenario --
whether it happens infrequently enough not to worry about, whether it's worth
implementing more sophisticated heuristics for avoiding it, or whether we're
better off just ignoring all stack traces that end in a function without unwind
info.

[Nico, 2015-08-16 01:32:00]

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
File base/profiler/native_stack_sampler_win.cc (right):

https://codereview.chromium.org/1263403002/diff/20001/base/profiler/native_st...
base/profiler/native_stack_sampler_win.cc:146: // We blacklist the module as
untrustable for unwinding if we encounter a
On 2015/08/16 00:54:11, Mike Wittman wrote:
> On 2015/08/15 01:44:18, Nico (hiding) wrote:
> > Is this blacklisting useful? You're expecting some amount of crashes if case
2
> > happens at the top (right?)
> 
> That's correct, but the blacklisting should substantially mitigate the
frequency
> of these crashes.
> 
> > ... so this only helps for 3rd-party modules that have
> > invalid abi stuff but never have any leaf functions while sampling.
> 
> No, the blacklisting makes it OK to encounter case 2 functions in these
modules
> at the top of the stack while sampling, *if* our first encounter of a case 2
> function in the module is in a frame below the top of the stack. When that
> happens we know the function is bad and record the module in the blacklist.
> If/when we later encounter any function in the module at the top of the stack,
> we assume it might be case 2 and don't continue the stack unwinding.
> 
> Where the blacklist doesn't help is if our first encounter of a case 2
function
> in a module is at the top frame in the stack. Then, we don't know any better,
so
> pop RSP to get the return address, and likely crash.
> 
> > That seems
> > not super useful to me – can you motivate why this blacklisting is useful a
> bit
> > more?
> 
> The last time we enabled this functionality we blindly popped RSP whenever we
> didn't get unwind information, even if we weren't at the top of the stack. We
> saw 184 crashes, all apparently due to either an injected third party module
> that was hooking Win32 or that had set its own WndProc. The vast majority were
> obviously due to case 2 in frames below the top of the stack. These crashes
> would be fixed by this change. 
> 
> Of the other crashes, it's not clear how many were case 2 at the top of the
> stack vs. just being difficult to tell what was going on.
> 
> Crash data from this change should make clear the frequency of encountering
case
> 2 at the top of the stack as the first encounter of a case 2 function in a
> module. This will inform a decision about how to deal with this scenario --
> whether it happens infrequently enough not to worry about, whether it's worth
> implementing more sophisticated heuristics for avoiding it, or whether we're
> better off just ignoring all stack traces that end in a function without
unwind
> info.

Ok, fair enough.

[Mike Wittman, 2015-08-18 21:11:10]

Patchset #3 (id:40001) has been deleted

[Mike Wittman, 2015-08-18 21:16:56]

I've refactored the code to use a testable stack unwinding interface, and added
unit tests.

This makes the implementation somewhat more complex but it doesn't negatively
affect performance, so on the whole I think it's probably a net positive.

Please take another look.

[Nico, 2015-08-18 23:20:25]

lgtm, thanks!

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder.h (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder.h:31: virtual PRUNTIME_FUNCTION
LookupFunctionEntry(DWORD64 program_counter,
LookUp ("look up" is a verb, "lookup" a noun)

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder_unittest.cc (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:48: next_image_base_(1 <<
20),
s/1 << 20/kImageBaseIncrement/ (?)

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:111:
scoped_ptr<Win32StackFrameUnwinder> unwinder = CreateUnwinder();
Can't this just live on the stack? (also below) Then you don't need
CreateUnwinder().

[Mike Wittman, 2015-08-18 23:43:11]

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder.h (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder.h:31: virtual PRUNTIME_FUNCTION
LookupFunctionEntry(DWORD64 program_counter,
On 2015/08/18 23:20:24, Nico wrote:
> LookUp ("look up" is a verb, "lookup" a noun)

Sure, but I'm just mimicking the Win32 API names here.

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder_unittest.cc (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:48: next_image_base_(1 <<
20),
On 2015/08/18 23:20:24, Nico wrote:
> s/1 << 20/kImageBaseIncrement/ (?)

Done.

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:111:
scoped_ptr<Win32StackFrameUnwinder> unwinder = CreateUnwinder();
On 2015/08/18 23:20:24, Nico wrote:
> Can't this just live on the stack? (also below) Then you don't need
> CreateUnwinder().

It could, but I believe I'd have to do one of: make the
Win32StackFrameUnwinder(UnwindFunctions*) constructor public, friend every test
function separately, or construct with placement new in
Win32StackFrameUnwinderTest. This seemed like the least bad option.

[Mike Wittman, 2015-08-18 23:43:59]

wittman@chromium.org changed reviewers:
+ cpu@chromium.org

[Mike Wittman, 2015-08-18 23:43:59]

Carlos, do you want to take a look at this now that you're back?

[Nico, 2015-08-18 23:49:48]

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder_unittest.cc (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:111:
scoped_ptr<Win32StackFrameUnwinder> unwinder = CreateUnwinder();
On 2015/08/18 23:43:10, Mike Wittman wrote:
> On 2015/08/18 23:20:24, Nico wrote:
> > Can't this just live on the stack? (also below) Then you don't need
> > CreateUnwinder().
> 
> It could, but I believe I'd have to do one of: make the
> Win32StackFrameUnwinder(UnwindFunctions*) constructor public, friend every
test
> function separately, or construct with placement new in
> Win32StackFrameUnwinderTest. This seemed like the least bad option.

Maybe add a "// This exists so that Win32StackFrameUnwinder's constructor can be
private with a single friend" type of comment above CreateUnwinder then.

[Mike Wittman, 2015-08-18 23:58:18]

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
File base/profiler/win32_stack_frame_unwinder_unittest.cc (right):

https://codereview.chromium.org/1263403002/diff/60001/base/profiler/win32_sta...
base/profiler/win32_stack_frame_unwinder_unittest.cc:111:
scoped_ptr<Win32StackFrameUnwinder> unwinder = CreateUnwinder();
On 2015/08/18 23:49:48, Nico wrote:
> On 2015/08/18 23:43:10, Mike Wittman wrote:
> > On 2015/08/18 23:20:24, Nico wrote:
> > > Can't this just live on the stack? (also below) Then you don't need
> > > CreateUnwinder().
> > 
> > It could, but I believe I'd have to do one of: make the
> > Win32StackFrameUnwinder(UnwindFunctions*) constructor public, friend every
> test
> > function separately, or construct with placement new in
> > Win32StackFrameUnwinderTest. This seemed like the least bad option.
> 
> Maybe add a "// This exists so that Win32StackFrameUnwinder's constructor can
be
> private with a single friend" type of comment above CreateUnwinder then.

Done.

[cpu_(ooo_6.6-7.5), 2015-08-19 19:07:24]

Scary indeed. I stared at it for a while and it looks correct

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
File base/profiler/win32_stack_frame_unwinder.cc (right):

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
base/profiler/win32_stack_frame_unwinder.cc:19: // encountered as the last frame
on the call stack.
can you add an example of this kind of function?

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
base/profiler/win32_stack_frame_unwinder.cc:29: // RecordStack will eventually
deadlock on a heap lock.
we can make RecoardStack allocate from a different heap. This is not difficult
on Windows.

[Mike Wittman, 2015-08-19 19:54:41]

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
File base/profiler/win32_stack_frame_unwinder.cc (right):

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
base/profiler/win32_stack_frame_unwinder.cc:19: // encountered as the last frame
on the call stack.
On 2015/08/19 19:07:24, cpu wrote:
> can you add an example of this kind of function?

Done.

https://codereview.chromium.org/1263403002/diff/100001/base/profiler/win32_st...
base/profiler/win32_stack_frame_unwinder.cc:29: // RecordStack will eventually
deadlock on a heap lock.
On 2015/08/19 19:07:24, cpu wrote:
> we can make RecoardStack allocate from a different heap. This is not difficult
> on Windows.

Ah, I didn't mean for this comment to imply that RecordThread allocates memory.
Updated to be clear about the specific deadlock concern.

[cpu_(ooo_6.6-7.5), 2015-08-21 19:49:27]

lgtm

[cpu_(ooo_6.6-7.5), 2015-08-21 19:55:22]

the updated comment by the way says the same to me, that is we suspend a thread
which is holding a heap lock and now we try to allocate something and deadlock.

If we use our own heap
https://msdn.microsoft.com/en-us/library/windows/desktop/aa366599(v=vs.85).aspx
they can never take our lock.

[Mike Wittman, 2015-08-21 20:04:37]

On 2015/08/21 19:55:22, cpu wrote:
> the updated comment by the way says the same to me, that is we suspend a
thread
> which is holding a heap lock and now we try to allocate something and
deadlock.
> 
> If we use our own heap
>
https://msdn.microsoft.com/en-us/library/windows/desktop/aa366599(v=vs.85).aspx
> they can never take our lock.

OK. Do we have a C++ allocator class already that ties to this? Unless the stack
unwinding functionality gets a lot more involved it doesn't seem worth the
complexity of implementing one just for this purpose.

[Mike Wittman, 2015-08-23 20:28:38]

The CQ bit was checked by wittman@chromium.org

[Mike Wittman, 2015-08-23 20:28:39]

The patchset sent to the CQ was uploaded after l-g-t-m from
zturner@chromium.org, thakis@chromium.org
Link to the patchset: https://codereview.chromium.org/1263403002/#ps140001
(title: "rebase")

[commit-bot: I haz the power, 2015-08-23 20:28:49]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1263403002/140001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1263403002/140001

[commit-bot: I haz the power, 2015-08-23 21:22:26]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2015-08-23 21:22:27]

Try jobs failed on following builders:
  mac_chromium_rel_ng on tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_rel_...)

[Mike Wittman, 2015-08-23 23:39:55]

The CQ bit was checked by wittman@chromium.org

[Mike Wittman, 2015-08-23 23:39:56]

The patchset sent to the CQ was uploaded after l-g-t-m from
zturner@chromium.org, thakis@chromium.org, cpu@chromium.org
Link to the patchset: https://codereview.chromium.org/1263403002/#ps160001
(title: "fix GN link")

[commit-bot: I haz the power, 2015-08-23 23:39:59]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1263403002/160001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1263403002/160001

[commit-bot: I haz the power, 2015-08-24 00:43:01]

Committed patchset #8 (id:160001)

[commit-bot: I haz the power, 2015-08-24 00:43:45]

Patchset 8 (id:??) landed as
https://crrev.com/863f84165da958298516064732d4d5b62ad7eb59
Cr-Commit-Position: refs/heads/master@{#345012}

[Nico, 2015-08-24 02:46:53]

This breaks the win/clang build, can you fix please?

In file included from ..\..\base\profiler\native_stack_sampler_win.cc:13:
..\..\base/profiler/win32_stack_frame_unwinder.h(48,5) : error: [chromium-style]
'virtual' is redundant; 'override' implies 'virtual'.
    virtual PRUNTIME_FUNCTION LookupFunctionEntry(DWORD64 program_counter,
    ^~~~~~~~
..\..\base/profiler/win32_stack_frame_unwinder.h(51,5) : error: [chromium-style]
'virtual' is redundant; 'override' implies 'virtual'.
    virtual void VirtualUnwind(DWORD64 image_base, DWORD64 program_counter,
    ^~~~~~~~
2 errors generated.

http://build.chromium.org/p/chromium.fyi/builders/CrWinClang/builds/2782/step...

[Nico, 2015-08-24 03:33:15]

nvm, got it: https://codereview.chromium.org/1313543002/

On Sun, Aug 23, 2015 at 7:46 PM, <thakis@chromium.org> wrote:

> This breaks the win/clang build, can you fix please?
>
> In file included from ..\..\base\profiler\native_stack_sampler_win.cc:13:
> ..\..\base/profiler/win32_stack_frame_unwinder.h(48,5) : error:
> [chromium-style]
> 'virtual' is redundant; 'override' implies 'virtual'.
>     virtual PRUNTIME_FUNCTION LookupFunctionEntry(DWORD64 program_counter,
>     ^~~~~~~~
> ..\..\base/profiler/win32_stack_frame_unwinder.h(51,5) : error:
> [chromium-style]
> 'virtual' is redundant; 'override' implies 'virtual'.
>     virtual void VirtualUnwind(DWORD64 image_base, DWORD64 program_counter,
>     ^~~~~~~~
> 2 errors generated.
>
>
>
http://build.chromium.org/p/chromium.fyi/builders/CrWinClang/builds/2782/step...
>
> https://codereview.chromium.org/1263403002/
>

To unsubscribe from this group and stop receiving emails from it, send an email
to chromium-reviews+unsubscribe@chromium.org.