Further reading for priorities of hotkeys: https://bugs.chromium.org/p/chromium/issues/detail?id=383558#c2

Assessment:
I've been running my tests with ~5 tabs loaded to google.com with a query. google.com has an unload handler [but it runs very quicly]. When I hold down cmd + w, the browser main thread is pretty much blocked working on processing the events. Each event takes ~100ms to process. This seems to be clogging up the main thread to the point where Chrome is incapable of doing anything.

[This is surprising. I would expect the relevant tasks to be queued up and be interspersed among the event-handling tasks. Zooming in, we see that there is a ~1ms between event-handling tasks where Chrome gets to run a couple of tasks, and the main thread even has some down time. I'm not sure exactly what's going on here - needs further research].

Tracing shows that the call ([[NSApp mainMenu] performKeyEquivalent:event]) always takes about 100ms for cmd+w, regardless of whether it's held down. Taking a sample [attached] reveals the relevant lines:

    +                             !       :     |   +       ! 2369 +[BrowserWindowUtils handleKeyboardEvent:inWindow:]  (in libchrome_dll.dylib) + 812  [0x11081a64c]  browser_window_utils.mm:71
    +                             !       :     |   +       ! : 2369 -[NSMenu performKeyEquivalent:]  (in AppKit) + 357  [0x7fff888627a5]
    +                             !       :     |   +       ! :   2367 _os_activity_initiate  (in libsystem_trace.dylib) + 75  [0x7fff8953e07a]
    +                             !       :     |   +       ! :   | 2320 -[NSCarbonMenuImpl performActionWithHighlightingForItemAtIndex:]  (in AppKit) + 124  [0x7fff888638c1]
    +                             !       :     |   +       ! :   | + 2319 CFRunLoopRunSpecific  (in CoreFoundation) + 296  [0x7fff91f80ed8]
    +                             !       :     |   +       ! :   | + ! 2275 __CFRunLoopRun  (in CoreFoundation) + 1356  [0x7fff91f8168c]
    +                             !       :     |   +       ! :   | + ! : 2275 __CFRunLoopServiceMachPort  (in CoreFoundation) + 212  [0x7fff91f821c4]
    +                             !       :     |   +       ! :   | + ! :   2275 mach_msg  (in libsystem_kernel.dylib) + 55  [0x7fff95b063b3]
    +                             !       :     |   +       ! :   | + ! :     2275 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff95b06f72]

This is pretty much totally outside of our control. 

I tried changing BrowserWindowCocoa::PreHandleKeyboardEvent() so that if (browser_->command_controller()->IsReservedCommandOrKey(id, event)), then call chrome::ExecuteCommand(browser_, id);  instead of [BrowserWindowUtils handleKeyboardEvent:event.os_event inWindow:window()]. This circumvents the call to AppKit, and also fixes the close tab bug.

Unfortunately, the following lines in browser_window_utils.mm implies that we can't just skip this call:
"""
 64     // Send the event to the menu before sending it to the browser/window       
 65     // shortcut handling, so that if a user configures cmd-left to mean         
 66     // "previous tab", it takes precedence over the built-in "history back"     
 67     // binding. Other than that, the |-redispatchKeyEvent:| call would take care
 68     // of invoking the original menu item shortcut as well.          
"""

Deleted: close_tab_sample.txt 306 KB

close_tab_sample.txt 306 KB View Download

Changing the behavior of IDC_CLOSE_TAB to do nothing shows that it still takes 100ms to process [[NSApp mainMenu] performKeyEquivalent:event]. Ditto for other hotkeys like cmd+s.

TextEdit repeated hotkeys seem to work fine (opening and closing windows). It also responds correctly to changes in hotkeys via system preferences. I wonder if Chrome is somehow doing something wrong? No more time to look at this for now.

I wrote a test app with custom menu bar items. Invoking them is really fast (<1ms), so Chrome is doing something wrong with the way it's set up the Menu Bar.

Starting to make some progress.

Observation 1: Each hotkey always takes 100ms to process. The sample shows that we're stuck in CFRunLoopRunSpecific

Observation 2: The implementation of [NSCarbonMenuImpl performActionWithHighlightingForItemAtIndex:] does the following:
  2a) Highlight menu item
  2b) perform action
  2c) unhighlight menu item.

The sample implies that we're stuck in (2c). Looking at the implementation for __NSUnhighlightCarbonMenu [pseudo is translation by me]:

if (dyld_get_program_sdk_version() < 10.10.255) [deployment target?] {
  if (linked SDK >= 10.10)
    mode = NSUnhighlightMenuRunLoopMode
  else
    mode = NSEventTrackingRunLoopMode
CFRunLoopRunInMode(mode, until = now + 0.1)
}
  
Ah ha! Now we see where the 0.1 seconds is coming from. We're stuck in __NSUnhighlightCarbonMenu waiting for something to exit the nested run loop. For some reason, this isn't happening so we hit the 0.1s timeout.

My test app from c#5 was not testing the right thing. The new test app I'm attaching also has the same issue [main thread blocked for 0.1 seconds]. 

Here's what's happening: 
_unhighlightMenuBarAtTime is passed a time [current time + 0.1 seconds]. It adds a timer to the cfrunloop to fire at that time. __NSUnhighlightCarbonMenu waits until this timer fires, and then unhighlights the menu bar. :(

Setting the deployment target to 10.11 doesn't make the problem go away in the test app, and I haven't looked into dyld_get_program_sdk_version yet. I don't think that's a good use of time, since we will be supporting 10.9 and 10.10 for some time yet.

Deleted: testmenubar.zip 47.6 KB

testmenubar.zip 47.6 KB Download

The reason that holding down cmd+w appears to do "nothing" is that it queues up a bunch of events in the run loop, each of which requires 0.1s to process. These prevent Chrome's queued tasks from running [and these queued tasks block Chrome from closing tabs]. 

Two solutions come to mind. Neither is great: 
1) Interpose the implementation of __NSUnhighlightCarbonMenu to unhighlight the menu without spinning a nested loop for 0.1 s. 
2) Don't call handleKeyboardEvent: on known hotkeys. This will prevent the menu highlighting, which is not great. It also requires Chrome to know about hotkey remappings, which is neither easy nor robust.

Unfortunately, this bug is probably going to end up in the WontFix bucket. 

+ rsesek, mark to see if either of them have ideas.

Random thought: I guess we could modify our Run Loop to give Chrome tasks a higher priority than NSEvents.

Discussed offline.

You could, but then you would need to know when to drop back to the old priority. In the absence of that, we're playing chicken with the task system.

It sounds like the root of the issue is the 0.1s wait on the main thread when going through the menu code. If there is a way to avoid that while providing equivalent functionality, that sounds like it might be the way to go.  

Safari's behavior is much better than Chrome's. It closes about 1 tab every 0.1-0.2 seconds. This suggests that they have some type of throttling for input events, or some way of prioritizing their own tasks [like Chrome, they still have to respect onUnload observers, so we know they have to asynchronously go off and do some work].

If we used the known hotkey mapping to avoid handleKeyboardEvent:, we could still manually flash the appropriate menu using HiliteMenu. We would have to worry about conflicting with AppKit's use of the same method.

Okay. More discussion with Rob.

Thought #1: To a large extent, the problem is that we have two work queues (NSEvents, Chrome tasks), and we're only pulling work from one of the work queues (NSEvents) which is why none of the tabs appear to close. 

If you take [BrowserCrApplication sendEvent:] and dispatch the events as Chrome tasks onto the Chrome task queue, the problem isn't fixed, but is highly alleviated. [Eventually, the Chrome task queue still ends up getting swamped with no-op Cmd-W events, each of which takes 0.1s to process.]

Thought #2: The reason that after letting go of cmd+w, no further tabs are closed is because when the TabManager gets a "close current tab command", and it is in the process of closing the current tab, it ignores the command. Rob put forth a good argument that the TabManager should close the next tab. [e.g. you're typing on Google Docs and the UI has stalled. If you press "w" 5 times, you expect to see all 5 "w"s show up on the page. Likewise for closing tabs.]

The root of the problem [if you ignore the 0.1s main thread spin] is that there are two task queues [NSEvents, Chrome Tasks] and the Chrome Task queue is getting starved. 

Chrome wants to run a bunch of really fast tasks {<1ms}. AppKit is shoving events into its queue that each takes 0.1s to complete. We could implement a scheduler. If there are tasks in both queues, pull one task from each until one of the queues is empty. If we wanted to be smarter, we could do a time-based scheduler [rather than # of tasks].

When the task scheduler is turned on for the UI thread, this problem will likely be fixed [since they will introduce a more sane scheduling than the one we currently use].  That's still multiple quarters out, but given that this issue has been around for many years, it can wait a while longer.

robliao@, Is there a tracking bug for turning on the task scheduler on the UI thread? If so, can you mark it as a blocker?

I'm not convinced scheduler on the main thread makes sense / will ever happen. Things on the main thread may move to the scheduler though. i.e. things on the UI thread could eventually be merely the few things that truly need to be affine to the main UI thread (e.g. HWNDs).

While the scheduler may not fully manage the main thread, it would be useful to see if we can integrate our scheduling logic to the UI thread. Currently, each platform has its own way of time-sharing between Chrome tasks and UI messages. It may be useful to have a way to prioritize these.

Re: c#13 and c#7, I guess the run loop is in a special mode and there is code waiting for the 0.1s timer to fire before exiting the run loop from the mode? Is it possible to have our own timer fire in that mode that triggers running of a queued-up Chrome task? That way the Chrome tasks get processed while we're waiting for the Appkit to finish it's menu stuff?

shrike: There's a nested runloop, so we would only be able to run re-entrant safe tasks. Most of our tasks are not. 

Got it.

I tried out Safari and see how it's fast, but as you note it's not faster than 0.1s per close. Re: c#11, why do you suspect they're doing something special? I doubt key repeat is faster than 100ms, so I'm guessing they are just closing each tab as each new Cmd-W arrives.

To put it another way, it seems like we're focusing on the 100ms delay but if we could close a tab every 100ms that would be great. Is it that we are not executing all the pending Chrome tasks once the nested run loop ends and we're told to perform the tab close?

This bug has bits and pieces of the sequence of events spread through the comments, but no one place that documents it all, step-by-step. Would it be possible to put your findings into a design doc that would make it easier to discuss possible strategies for fixing this?

Re. #18, FTR, most of our tasks *do* run from a nested runloop. In fact, according to code search, there are only 17 calls to PostNonNestableTask() outside of tests.

I took erikchen@'s comment about nested run loops to refer to nested AppKit runloops, but see now that he's probably talking about Chrome run loops. Seems like there's a similar potential issue on the AppKit side.

Design doc that captures the full problem:
https://docs.google.com/document/d/1W-qJT2T5-HV-pdggE80t5k-TdhTOoRBJ2bzJv00tDVU/edit

Really great and helpful - thank you for doing that!

The issue of nested runloops is a bit complicated. Chrome tasks are handled using this chain of calls:

MessageLoop::Run --> -[NSApp run] --> -[NSApp nextEventMatchingMask:] --> CFRunLoopRun --> MessageLoop callouts --> base::Closure

The issue is that the NSApplication loop processes events outside of the CFRunLoopRun callouts. This leads to starvation if an event handler spins the runloop itself:

MessageLoop::Run --> -[NSApp run] --> -[NSApp sendEvent:]

Both the MessageLoop and NSApp have a unique way of limiting task reentrancy. For MessageLoop, we have SetNestableTasksAllowed. Without that flag, the MessageLoop is only serviced if there is one call to MessageLoop::Run on the stack. AppKit limits nesting by running the CFRunLoop in specific modes other than Common and Default. By excluding Common modes, the loop avoids servicing other work that could then cause reentrancy problems.

In the case of this bug, the _NSUnhighlightCarbonMenu function spins the runloop exclusively in the mode NSUnhighlightMenuRunLoopMode. This starves the MessageLoop because its callouts only get serviced in Common modes.

When AppKit does this, it's not quite true that the MessageLoop is nested, because a Chrome task is not running the MessageLoop again. The runloop is definitely nested, and AppKit is trying to defend against reentrancy, but the Chrome tasks *could* be pumped.

Note that this same issue happens with video playback in issue 604816 and web animations when closing select menus in issue 652007.

With this patch, holding Cmd+W is a bit (but not a lot) smoother: https://codereview.chromium.org/2118883002/diff/20001/base/message_loop/message_pump_mac.mm

By default, neither AppKit nor Chrome tasks are re-entrant safe. I don't think that allowing re-entrancy is a good solution to this problem [I don't think you'r suggesting this either, but you did have a long post about it]. Making sure that the Chrome task queue doesn't get starved using a smarter scheduler [will require rearchitecture of MessageLoop] seems like the best approach to me. If AppKit decides it needs to block the main thread for 0.1, then let it do so, but don't let it do so 20 times in a row while no Chrome tasks run.

No, I'm not proposing that we allow reentrant tasks. I am suggesting that we consider scheduling Chrome tasks in various private AppKit runloop modes, so that it doesn't starve our tasks.

This opens the possibility of reentrancy. e.g.

Chrome task A calls AppKit method that spins a nested run loop with a private runloop mode. Now we allow Chrome tasks to be run in the nested runloop.

Perhaps I'm misunderstanding what you're trying to do. Let's discuss more in the scheduled meeting.

We discussed two solutions offline:
(1) Better scheduling AppKit vs Chrome tasks. mark@ says that we've tried this before but failed to get it working. This should be do-able, but there might be implicit dependencies between AppKit and Chrome tasks that need to be weaseled out.

(2) rsesek's proposal. See c#24. The main concern is that this might cause Chrome task's to become re-entrant. [e.g. Chrome task calls AppKit method that runs nested run loop in private mode, which we change to be able to invoke Chrome tasks]. This can be guarded against explicitly. There are other re-entrancy possibilities, but it should be possible to guard against them all. 

The plan is to move forward with (2).

 Issue 462379  has been merged into this issue.

Fun Fact: This works better in Incognito windows. Tabs do close as Ctrl+W is held down.  Why on earth would that be different than a regular profile window is certainly interesting.

Available, but no owner or component? Please find a component, as no one will ever find this without one.