Friday, July 13, 2012

What happens when you switch to a Gmail tab on OS X

What follows is a brief walk through of what happens when you switch to a Gmail tab. You can follow along in the profile.

The process starts with [GeckoNSApplication sendEvent:] for the mouse event. This travels on down to nsXBLEventHander::HandleEvent(). From there, we call into the JS, specifically onxblmousedown() in tabbox.xml(). This eventually calls into set__selected() and set_selectedPanel(). set_selectedIndex() calls onselect() in browser.xul which ends up taking about 14ms. During onselect() we spend 4ms decoding an image, 3 ms in callProgressListeners() and 3ms in GetBoundingClientRect(). The whole process of handling the click event takes about 15ms.

After that we spend 6ms handling some events. Among these are a RefreshDriver tick and a toolkit paint. Afterwards we wait for 12ms.

33 ms after the original click we start the painting process. First we do a [NSView viewWillDraw] which calls in PresShell::WillPaint() and takes 3ms. Finally we start the actual 85 ms paint in PresShell::Paint().

Here's the breakdown of what we doing during paint. Of the 85 ms, 81 ms is in LayerManagerOGL::Render(). 5ms of that is clearing the surface in BasicBufferOGL::BeginPaint(), 11 ms is texture upload which does a useless format conversion (bug 613046). In between these two is 58ms of DrawThebesLayer() of which 39 ms is BasicLayerManager::EndTransactionInternal doing composition. A lot of this seems to be vm badness caused by cairo/CoreGraphics and it's weird copy-on-write semantics. The rest of the time is 6ms in nsDisplayText::Paint, 5 ms in nsDisplayBackground::Paint, 4 ms in nsDisplayBorderBackground::Paint, and 3ms in nsDisplayBorder::Paint(). Unfortunately, of the 85 ms only 18ms of the time is painting display items and of the 18ms less than half of that is actual painting operations inside of CoreGraphics.

Shortly after PresShell::Paint() the new content is displayed on the screen and we run a couple more different events and a garbage collection.  And that's what happens during the 130ms switch to a Gmail tab.