chromium/src
0
Fork 0
Code Activity

Revert "[Reland] Add DumpWithoutCrash for slow Mac KeyPress events"

Browse Source 
This reverts commit 23d79be238.

Reason for revert: Crash dumps are no longer needed

Original change's description:
> [Reland] Add DumpWithoutCrash for slow Mac KeyPress events
>
> [Reland] - This is effectively a reland, first patchset is unchanged
> https://crrev.com/74f12a609316ba81 so compare to that for changes. That
> iteration provided some interesting data but used a triggering time of 5
> seconds. I've since learned that there's a myriad of known edge-cases in
> which events might have delays of 1-20 seconds (!). In our case, we're
> specifically looking for issues at the upper end of the UMA metric (60+
> seconds) so this caused some unrelated noise. This CL relands with a
> higher threshold and some minor changes to the crash keys.
>
> Add a DumpWithoutCrash to KeyPress events where the timestamp of the OS
> differs from the current time by more than 60 seconds. We see in UMA
> that we often see events in the 95% percentile reaching many seconds of
> difference. Hopefully the crash stacks will reveal something about
> what's causing this.
>
> A previous iteration of this investigation in
> https://crrev.com/c/2111782 showed that we sometimes redispatch events
> that have been reinjected back from the renderer. This should never
> happen. This CL adds crash keys to dump some of the related app state
> to help explain how this happens.
>
> However, not all such stack traces showed reinjection so that can't be
> the cause of all these bad timestamps. This CL also adds some timing
> information to the existing crash key in NSApp:sendEvent which might
> reveal something.
>
> Bug: 1039833
> Change-Id: If49b7b8a918f880ed00a7adf219e589ed66daf6e
> Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2210867
> Commit-Queue: David Bokan <bokan@chromium.org>
> Reviewed-by: Avi Drissman <avi@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#771059}

TBR=avi@chromium.org,bokan@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 1039833,1070998
Change-Id: Ia8ba77a1ee95d033f7626055013d15422da32b27
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2310390
Reviewed-by: David Bokan <bokan@chromium.org>
Reviewed-by: Avi Drissman <avi@chromium.org>
Commit-Queue: David Bokan <bokan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#790485}
This commit is contained in:
David Bokan
2020-07-21 19:14:04 +00:00
committed by Commit Bot
parent c7bd40c4d0
commit 87b556b150
5 changed files with 1 additions and 117 deletions

11
chrome/browser/chrome_browser_application_mac.mm

@ -21,7 +21,6 @@
#include "content/public/browser/native_event_processor_mac.h"
#include "content/public/browser/native_event_processor_observer_mac.h"
#include "ui/base/cocoa/accessibility_focus_overrider.h"
#include "ui/events/base_event_utils.h"
namespace chrome_browser_application_mac {
@ -95,16 +94,6 @@ std::string DescriptionForNSEvent(NSEvent* event) {
default:
break;
}
// TODO(bokan): Added temporarily to debug https://crbug.com/1039833.
base::TimeTicks event_timestamp =
ui::EventTimeStampFromSeconds([event timestamp]);
base::TimeTicks now = ui::EventTimeForNow();
base::TimeDelta diff = now - event_timestamp;
desc += base::StringPrintf(" Now: %lld Diff: %lld",
(now - base::TimeTicks()).InSeconds(),
diff.InSeconds());
return desc;
}

82
content/app_shim_remote_cocoa/render_widget_host_view_cocoa.mm

@ -120,78 +120,6 @@ SkColor SkColorFromNSColor(NSColor* color) {
base::ClampToRange(static_cast<int>(lroundf(255.0f * b)), 0, 255);
}
// TODO(bokan): Added temporarily to debug https://crbug.com/1039833.
// Needed only in temporary method below.
CommandDispatcher* GetCommandDispatcher(NSWindow* theWindow) {
if ([theWindow conformsToProtocol:@protocol(CommandDispatchingWindow)]) {
return [static_cast<NSObject<CommandDispatchingWindow>*>(theWindow)
commandDispatcher];
}
return nil;
}
// TODO(bokan): Added temporarily to debug https://crbug.com/1039833.
// Returns a string with class names of each ancestor view of this one
// (inclusive).
std::string GetViewHierarchyString(NSView* thisView) {
std::string ret = "";
NSView* view = thisView;
while (view) {
ret += base::SysNSStringToUTF8(NSStringFromClass([view class])) + "->";
view = [view superview];
}
return ret;
}
// TODO(bokan): Added temporarily to debug https://crbug.com/1039833.
// Returns a string with information about all the app's windows and current
// event redispatch state of this window and the event's window.
std::string GetWindowInfoString(NSWindow* thisWindow, NSEvent* theEvent) {
std::string windowInfoStr = "[";
NSArray* windows = [NSApp windows];
bool foundEventWindow = false;
for (unsigned int i = 0; i < [windows count]; ++i) {
NSWindow* window = windows[i];
if (thisWindow == window)
windowInfoStr += "S-";
if ([NSApp keyWindow] == window)
windowInfoStr += "K-";
if ([NSApp mainWindow] == window)
windowInfoStr += "M-";
if ([theEvent windowNumber] == [window windowNumber]) {
foundEventWindow = true;
windowInfoStr += "E-";
}
std::string className =
base::SysNSStringToUTF8(NSStringFromClass([window class]));
NSRect rect = [window frame];
windowInfoStr += base::StringPrintf(
"%ld<%s - %dx%d>, ", static_cast<long>([window windowNumber]),
className.c_str(), static_cast<int>(NSWidth(rect)),
static_cast<int>(NSHeight(rect)));
}
windowInfoStr += "]";
if (!foundEventWindow)
windowInfoStr += base::StringPrintf(
" E: %ld", static_cast<long>([theEvent windowNumber]));
windowInfoStr += base::StringPrintf(
" R[t:%d e:%d]",
GetCommandDispatcher(thisWindow) == nil
? -1
: static_cast<int>(
[GetCommandDispatcher(thisWindow) isRedispatchingKeyEvent]),
GetCommandDispatcher([theEvent window]) == nil
? -1
: static_cast<int>([GetCommandDispatcher([theEvent window])
isRedispatchingKeyEvent]));
return windowInfoStr;
}
// Extract underline information from an attributed string. Mostly copied from
// third_party/WebKit/Source/WebKit/mac/WebView/WebHTMLView.mm
void ExtractUnderlines(NSAttributedString* string,
@ -1006,16 +934,6 @@ void ExtractUnderlines(NSAttributedString* string,
- (void)keyEvent:(NSEvent*)theEvent wasKeyEquivalent:(BOOL)equiv {
TRACE_EVENT1("browser", "RenderWidgetHostViewCocoa::keyEvent", "WindowNum",
[[self window] windowNumber]);
// TODO(bokan): Added temporarily to debug https://crbug.com/1039833.
static auto* windowInfoKey = base::debug::AllocateCrashKeyString(
"window-info", base::debug::CrashKeySize::Size256);
static auto* viewInfoKey = base::debug::AllocateCrashKeyString(
"view-info", base::debug::CrashKeySize::Size256);
base::debug::ScopedCrashKeyString scopedKeyWindow(
windowInfoKey, GetWindowInfoString([self window], theEvent));
base::debug::ScopedCrashKeyString scopedKeyView(viewInfoKey,
GetViewHierarchyString(self));
NSEventType eventType = [theEvent type];
NSEventModifierFlags modifierFlags = [theEvent modifierFlags];
int keyCode = [theEvent keyCode];

18
content/browser/renderer_host/input/web_input_event_builders_mac.mm

@ -35,7 +35,6 @@
#include <stdint.h>
#include "base/debug/dump_without_crashing.h"
#include "base/mac/mac_util.h"
#include "base/metrics/histogram_macros.h"
#include "base/strings/string_util.h"
@ -257,12 +256,6 @@ blink::WebMouseEvent::Button ButtonFromButtonNumber(NSEvent* event) {
blink::WebKeyboardEvent WebKeyboardEventBuilder::Build(NSEvent* event,
bool record_debug_uma) {
// TODO(bokan) Temporary to debug crbug.com/1039833.
// It's assumed that some clients may fall into a bad state and produce these
// bad timestamps on lots of subsequent events. To prevent sending an
// overwhelming amount of crash reports stop after sending 5.
static int dump_without_crashing_throttle = 5;
ui::ComputeEventLatencyOS(event);
base::TimeTicks now = ui::EventTimeForNow();
base::TimeTicks hardware_timestamp =
@ -274,18 +267,9 @@ blink::WebKeyboardEvent WebKeyboardEventBuilder::Build(NSEvent* event,
"Event.Latency.OS_NO_VALIDATION.POSITIVE.KEY_PRESSED", diff,
base::TimeDelta::FromMilliseconds(1),
base::TimeDelta::FromSeconds(60), 50);
// TODO(bokan) Temporary to debug crbug.com/1039833. We've seen in UMA
// that we often receive key press events with the OS timestamp differing
// from the current timestamp by 60+ seconds. Try to capture a few crash
// reports from the wild to see if we can find some pattern.
if (diff.magnitude() > base::TimeDelta::FromSeconds(60) &&
dump_without_crashing_throttle > 0) {
--dump_without_crashing_throttle;
base::debug::DumpWithoutCrashing();
}
}
}
ui::DomCode dom_code = ui::DomCodeFromNSEvent(event);
int modifiers =
ModifiersFromEvent(event) | ui::DomCodeToWebInputEventModifiers(dom_code);

3
ui/base/cocoa/command_dispatcher.h

@ -58,9 +58,6 @@ COMPONENT_EXPORT(UI_BASE)
- (void)dispatchUsingKeyModifiers:(id)sender
forHandler:(id<UserInterfaceItemCommandHandler>)handler;
// TODO(bokan): Temporary to help debug https://crbug.com/1039833.
- (BOOL)isRedispatchingKeyEvent;
@end
// If the NSWindow's firstResponder implements CommandDispatcherTarget, then

4
ui/base/cocoa/command_dispatcher.mm

@ -267,10 +267,6 @@ NSEvent* KeyEventForWindow(NSWindow* window, NSEvent* event) {
[[self bubbleParent] commandDispatchUsingKeyModifiers:sender];
}
- (BOOL)isRedispatchingKeyEvent {
return _isRedispatchingKeyEvent;
}
- (NSWindow<CommandDispatchingWindow>*)bubbleParent {
NSWindow* parent = [_owner parentWindow];
if (parent && [parent hasKeyAppearance] &&