Tracing for NSMenu timelines

ui/views/controls/menu/menu_runner_impl_cocoa.mm

Index: ui/views/controls/menu/menu_runner_impl_cocoa.mm
diff --git a/ui/views/controls/menu/menu_runner_impl_cocoa.mm b/ui/views/controls/menu/menu_runner_impl_cocoa.mm
index 62a758fcbd5e2f1dd6ca05a1fa8028a0537a7044..133a6ef0258e4cce0d08df7523bd78447ceb974b 100644
--- a/ui/views/controls/menu/menu_runner_impl_cocoa.mm
+++ b/ui/views/controls/menu/menu_runner_impl_cocoa.mm
@@ -4,16 +4,29 @@
 
 #import "ui/views/controls/menu/menu_runner_impl_cocoa.h"
 
+#import "base/mac/foundation_util.h"
 #include "base/mac/sdk_forward_declarations.h"
+#include "base/strings/sys_string_conversions.h"
 #import "ui/base/cocoa/menu_controller.h"
 #include "ui/base/models/menu_model.h"
 #include "ui/events/base_event_utils.h"
 #include "ui/events/event_utils.h"
 #include "ui/gfx/geometry/rect.h"
 #include "ui/gfx/mac/coordinate_conversion.h"
+#import "ui/views/cocoa/bridged_native_widget.h"
 #include "ui/views/controls/menu/menu_runner_impl_adapter.h"
+#include "ui/views/widget/native_widget_mac.h"
 #include "ui/views/widget/widget.h"
 
+// Extension of base's MenuController to observe when menu items are activated.
+@interface ViewsMenuController : MenuController
+// Sets an NSWindow to pump compositor frames before returning from
+// -[MenuController itemSelected:]. NSMenu blocks the UI thread until the NSMenu
+// highlight and fade animation completes, so this allows the compositing work
+// to be interleaved with the animation delay.
+- (void)setWindowToUpdate:(NSWindow*)window;
+@end
+
 namespace views {
 namespace internal {
 namespace {
@@ -101,8 +114,8 @@ MenuRunnerImplCocoa::MenuRunnerImplCocoa(
       delete_after_run_(false),
       closing_event_time_(base::TimeTicks()),
       on_menu_closed_callback_(on_menu_closed_callback) {
-  menu_controller_.reset(
-      [[MenuController alloc] initWithModel:menu useWithPopUpButtonCell:NO]);
+  menu_controller_.reset([[ViewsMenuController alloc] initWithModel:menu
+                                             useWithPopUpButtonCell:NO]);
 }
 
 bool MenuRunnerImplCocoa::IsRunning() const {
@@ -121,6 +134,58 @@ void MenuRunnerImplCocoa::Release() {
   }
 }
 
+CGEventRef Callback(CGEventTapProxy proxy,
+                    CGEventType type,
+                    CGEventRef event,
+                    void* userInfo) {
+  DLOG(INFO) << "event: " << type;
+  return NULL;
+}
+
+void MyRunLoopObserver(CFRunLoopObserverRef observer,
+                       CFRunLoopActivity activity,
+                       void* info) {
+  NSString* name = static_cast<NSString*>(info);
+  DLOG(INFO) << base::SysNSStringToUTF8(name) << " flags: " << activity;
+}
+
+class ScopedRunLoopSpy {
+ public:
+  ScopedRunLoopSpy() {
+    base::ScopedCFTypeRef<CFArrayRef> names(
+        CFRunLoopCopyAllModes(CFRunLoopGetCurrent()));
+    const CFIndex count = CFArrayGetCount(names);
+    for (CFIndex i = 0; i < count; ++i) {
+      base::scoped_nsobject<NSString> name(
+          base::mac::CFToNSCast(
+              static_cast<CFStringRef>(CFArrayGetValueAtIndex(names, i))),
+          base::scoped_policy::RETAIN);
+      NSLog(@"%@", name.get());
+      CFRunLoopObserverContext context = {0};
+      context.info = name;
+      CFRunLoopObserverRef observer = CFRunLoopObserverCreate(
+          NULL, kCFRunLoopAllActivities, YES, /* repeat */
+          0, &MyRunLoopObserver, &context);
+      modes[name] = observer;
+      CFRunLoopAddObserver(CFRunLoopGetCurrent(), observer,
+                           base::mac::NSToCFCast(name.get()));
+    }
+  }
+
+  ~ScopedRunLoopSpy() {
+    for (const auto& entry : modes) {
+      CFRunLoopRemoveObserver(CFRunLoopGetCurrent(), entry.second,
+                              base::mac::NSToCFCast(entry.first.get()));
+      CFRelease(entry.second);
+    }
+  }
+
+ private:
+  std::map<base::scoped_nsobject<NSString>, CFRunLoopObserverRef> modes;
+
+  DISALLOW_COPY_AND_ASSIGN(ScopedRunLoopSpy);
+};
+
 void MenuRunnerImplCocoa::RunMenuAt(Widget* parent,
                                     MenuButton* button,
                                     const gfx::Rect& bounds,
@@ -132,24 +197,40 @@ void MenuRunnerImplCocoa::RunMenuAt(Widget* parent,
   closing_event_time_ = base::TimeTicks();
   running_ = true;
 
+  CGEventMask event_mask = CGEventMaskBit(kCGEventLeftMouseUp);
+  CFMachPortRef port =
+      CGEventTapCreate(kCGAnnotatedSessionEventTap, kCGHeadInsertEventTap,
+                       kCGEventTapOptionListenOnly,  // passive listener.
+                       event_mask, &Callback, this);
+  auto* source = CFMachPortCreateRunLoopSource(NULL, port, 0);
+  CFRunLoopAddSource(CFRunLoopGetMain(), source, kCFRunLoopCommonModes);
+  CGEventTapEnable(port, true);
+
   if (run_types & MenuRunner::CONTEXT_MENU) {
     [NSMenu popUpContextMenu:[menu_controller_ menu]
                    withEvent:[NSApp currentEvent]
                      forView:parent->GetNativeView()];
   } else if (run_types & MenuRunner::COMBOBOX) {
+    [menu_controller_ setWindowToUpdate:parent->GetNativeWindow()];
     NSMenuItem* checked_item = FirstCheckedItem(menu_controller_);
     base::scoped_nsobject<NSView> anchor_view(
         CreateMenuAnchorView(parent->GetNativeWindow(), bounds, checked_item));
     NSMenu* menu = [menu_controller_ menu];
     [menu setMinimumWidth:bounds.width() + kNativeCheckmarkWidth];
+    ScopedRunLoopSpy spy;
     [menu popUpMenuPositioningItem:checked_item
                         atLocation:NSZeroPoint
                             inView:anchor_view];
+    DLOG(INFO) << "method return";
     [anchor_view removeFromSuperview];
   } else {
     NOTREACHED();
   }
 
+  CGEventTapEnable(port, false);
+  CFRelease(source);
+  CFRelease(port);
+
   closing_event_time_ = ui::EventTimeForNow();
   running_ = false;
 
@@ -177,3 +258,34 @@ MenuRunnerImplCocoa::~MenuRunnerImplCocoa() {
 
 }  // namespace internal
 }  // namespace views
+
+@implementation ViewsMenuController {
+  base::scoped_nsobject<NSWindow> windowToUpdate_;
+  BOOL compositorPumped_;
+}
+
+- (void)setWindowToUpdate:(NSWindow*)window {
+  windowToUpdate_.reset(window, base::scoped_policy::RETAIN);
+}
+
+- (views::BridgedNativeWidget*)widget {
+  return windowToUpdate_
+             ? views::NativeWidgetMac::GetBridgeForNativeWindow(windowToUpdate_)
+             : nullptr;
+}
+
+// MenuController overrides.
+
+- (BOOL)processItemSelectedEarly:(id)sender {
+  // Items that end in "..." indicate that a new window will be opened. Process
+  // those "late" so the windows transition at the correct times.
+  if ([[sender title] hasSuffix:@"…"])
+    return NO;
+
+  [self itemSelected:sender];
+  if (views::BridgedNativeWidget* nativeWidget = [self widget])
+    nativeWidget->PumpCompositor();
+  return YES;
+}
+
+@end