Skip to content

Instantly share code, notes, and snippets.

@esprehn
Created July 26, 2014 23:04
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save esprehn/80be9cf37d4f112c7229 to your computer and use it in GitHub Desktop.
Save esprehn/80be9cf37d4f112c7229 to your computer and use it in GitHub Desktop.
I profiled the starry night benchmark for 4 minutes, below is what I learned. There's a summary at the top, and analysis inline between each section of the trace.
Major take aways from profiling the starry night benchmark:
- Scrollbars are crazy expensive on OS X. We spend a 12.4% of the layout time and 16.5% of the recording time dealing with scrollbars.
- 5.6% of the time is spent starting a base::Timer on OS X to update the preferred size for the green bubble on OS X. Why is base::Timer::Start() so slow?
- updateLayerPositionsAfterLayout strikes again at 14% of the layout costs.
- core layout is extremely fast, it seems we just do "too much stuff" in general.
- Text recording (18% main thread) and rasterization (38% impl thread) are major factors.
- Rastering and clipping rounded rects is still too expensive (21% impl thread).
- recalcStyle is extremely fast and shows the usual things, matching rules, applying properties and updating the render tree. It's so fast the number of samples is somewhat low even though I profiled for 4 minutes. Even so it's far too expensive given that only max-height is actually changing, we might consider a fast path for animations here since we know rules didn't actually change only animated properties.
Action items seem to be:
- Make Text recording/rasterization at least 2x, if not 4x faster.
- Make updateLayerPositionsAfterLayout much faster
- Make Rastering rounded rects much faster.
- Scrollbars on OS X are destroying perf, needs to be at least 10x faster (this page only has a single scrollbar!)
- Figure out why base::Timer::Start is so expensive.
-- Analysis follows
Main thread BeginMainFrame time breakdown:
We spend most of the time (55%) in BeginMainFrame inside recording:
Running Time Self Symbol Name
20198.0ms 55.8% 13.0 cc::PictureLayer::Update(cc::ResourceUpdateQueue*, cc::OcclusionTracker<cc::Layer> const*)
5980.0ms 16.5% 4.0 non-virtual thunk to cc::PaintedScrollbarLayer::Update(cc::ResourceUpdateQueue*, cc::OcclusionTracker<cc::Layer> const*)
5972.0ms 16.4% 6.0 cc::PaintedScrollbarLayer::Update(cc::ResourceUpdateQueue*, cc::OcclusionTracker<cc::Layer> const*)
5166.0ms 14.2% 9.0 cc::PaintedScrollbarLayer::RasterizeScrollbarPart(gfx::Rect const&, gfx::Rect const&, cc::ScrollbarPart)
558.0ms 1.5% 1.0 cc::PaintedScrollbarLayer::UpdateThumbAndTrackGeometry()
Apparently painting the scrollbar is *crazy* expensive on OS X:
Running Time Self Symbol Name
5166.0ms 14.2% 9.0 cc::PaintedScrollbarLayer::RasterizeScrollbarPart(gfx::Rect const&, gfx::Rect const&, cc::ScrollbarPart)
3892.0ms 10.7% 4.0 content::ScrollbarImpl::PaintPart(SkCanvas*, cc::ScrollbarPart, gfx::Rect const&)
2770.0ms 7.6% 4.0 blink::WebScrollbarThemePainter::paintTrackBackground(SkCanvas*, blink::WebRect const&)
622.0ms 1.7% 5.0 blink::WebScrollbarThemePainter::paintThumb(SkCanvas*, blink::WebRect const&)
...
836.0ms 2.3% 9.0 SkCanvas::drawRect(SkRect const&, SkPaint const&)
PictureLayer::Update (which is recording) breaks down into:
Running Time Self Symbol Name
19600.0ms 54.1% 2490.0 blink::CompositedLayerMapping::doPaintTask(blink::GraphicsLayerPaintInfo const&, unsigned int const&, blink::GraphicsContext*, blink::IntRect const&)
6550.0ms 18.0% 40.0 blink::paintTextWithShadows(blink::GraphicsContext*, blink::Font const&, blink::TextRun const&, WTF::AtomicString const&, int, int, int, int, blink::FloatPoint const&, blink::FloatRect const&, blink::ShadowList const*, bool)
955.0ms 2.6% 125.0 blink::RenderBox::pushContentsClip(blink::PaintInfo&, blink::LayoutPoint const&, blink::ContentsClipBehavior)
895.0ms 2.4% 81.0 blink::RenderLayer::clipToRect(blink::LayerPaintingInfo const&, blink::GraphicsContext*, blink::ClipRect const&, unsigned int, blink::BorderRadiusClippingRule)
882.0ms 2.4% 51.0 blink::RenderBoxModelObject::paintBoxShadow(blink::PaintInfo const&, blink::LayoutRect const&, blink::RenderStyle const*, blink::ShadowStyle, bool, bool)
772.0ms 2.1% 61.0 blink::RenderLayer::paintOutlineForFragments(WTF::Vector<blink::LayerFragment, 1ul, WTF::DefaultAllocator> const&, blink::GraphicsContext*, blink::LayerPaintingInfo const&, unsigned int, blink::RenderObject*, unsigned int)
757.0ms 2.0% 22.0 blink::RenderBox::paintBackground(blink::PaintInfo const&, blink::LayoutRect const&, blink::Color const&, blink::BackgroundBleedAvoidance)
708.0ms 1.9% 46.0 blink::RenderBoxModelObject::paintBorder(blink::PaintInfo const&, blink::LayoutRect const&, blink::RenderStyle const*, blink::BackgroundBleedAvoidance, bool, bool)
536.0ms 1.4% 46.0 <Unknown Address>
460.0ms 1.2% 3.0 blink::RenderImage::paint(blink::PaintInfo&, blink::LayoutPoint const&)
439.0ms 1.2% 49.0 blink::InlineTextBox::logicalOverflowRect() const
389.0ms 1.0% 11.0 blink::RenderLayer::collectFragments(WTF::Vector<blink::LayerFragment, 1ul, WTF::DefaultAllocator>&, blink::RenderLayer const*, blink::LayoutRect const&, blink::ClipRectsCacheSlot, blink::OverlayScrollbarSizeRelevancy, blink::ShouldRespectOverflowClip, blink::LayoutPoint const*, blink::LayoutSize const&, blink::LayoutRect const*)
Most of the time is in blink::paintTextWithShadows, which spends nearly all of it's time inside GraphicsContext::drawPosText.
Running Time Self Symbol Name
6701.0ms 18.5% 0.0 Main Thread 0x70a27
6701.0ms 18.5% 41.0 blink::paintTextWithShadows(blink::GraphicsContext*, blink::Font const&, blink::TextRun const&, WTF::AtomicString const&, int, int, int, int, blink::FloatPoint const&, blink::FloatRect const&, blink::ShadowList const*, bool)
6653.0ms 18.3% 32.0 blink::GraphicsContext::drawText(blink::Font const&, blink::TextRunPaintInfo const&, blink::FloatPoint const&)
6469.0ms 17.8% 69.0 blink::Font::drawSimpleText(blink::GraphicsContext*, blink::TextRunPaintInfo const&, blink::FloatPoint const&) const
4616.0ms 12.7% 155.0 blink::Font::drawGlyphBuffer(blink::GraphicsContext*, blink::TextRunPaintInfo const&, blink::GlyphBuffer const&, blink::FloatPoint const&) const
4382.0ms 12.1% 172.0 blink::Font::drawGlyphs(blink::GraphicsContext*, blink::SimpleFontData const*, blink::GlyphBuffer const&, unsigned int, unsigned int, blink::FloatPoint const&, blink::FloatRect const&) const
3777.0ms 10.4% 23.0 blink::GraphicsContext::drawPosText(void const*, unsigned long, SkPoint const*, SkRect const&, SkPaint const&)
...
1740.0ms 4.8% 27.0 blink::Font::getGlyphsAndAdvancesForSimpleText(blink::TextRunPaintInfo const&, blink::GlyphBuffer&, blink::Font::ForTextEmphasisOrNot) const
1668.0ms 4.6% 30.0 blink::WidthIterator::advance(int, blink::GlyphBuffer*)
1543.0ms 4.2% 452.0 unsigned int blink::WidthIterator::advanceInternal<blink::Latin1TextIterator>(blink::Latin1TextIterator&, blink::GlyphBuffer*)
442.0ms 1.2% 442.0 blink::GlyphBuffer::add(unsigned short, blink::SimpleFontData const*, float)
390.0ms 1.0% 387.0 blink::Font::glyphDataAndPageForCharacter(int, bool, blink::FontDataVariant) const
259.0ms 0.7% 259.0 blink::WidthIterator::characterWidth(int, blink::GlyphData const&) const
There's also layout/style/invalidations:
Running Time Self Symbol Name
9221.0ms 25.4% 3.0 blink::FrameView::updateLayoutAndStyleForPainting()
8026.0ms 22.1% 16.0 blink::FrameView::updateLayoutAndStyleIfNeededRecursive()
5706.0ms 15.7% 13.0 blink::FrameView::layout(bool)
2256.0ms 6.2% 10.0 blink::Document::updateRenderTree(blink::StyleRecalcChange)
...
689.0ms 1.9% 2.0 blink::FrameView::invalidateTreeIfNeededRecursive()
484.0ms 1.3% 9.0 blink::RenderLayerCompositor::updateIfNeededRecursive()
If we focus on recalcStyle it breaks down into the usual suspects, it's mostly matching rules and applying properties. There's also the animation logic and setting the new style (and going through RenderLayer::styleChanged). It fans out pretty fast though, there's not many samples down there. 19.8% of the time is under ElementRuleCollector::collectMatchingRules rule matching and doing other work related to matching selectors. We might consider trying to cache the UA rule matching to get back that 5%.
applyMatchedProperties is 22% and applyAnimatedProperties is 5.9% most of which (5%) is CSSAnimations::calculateUpdate. Strangely we're spending 1.9% inside VisitedLinkState::determineLinkStateSlowCase which is almost all parsing urls (1.4%). While there's not many samples inside there, it's still suspicious this shows up because we should be caching the urls for <a> elements and not calling this method much. I should probably profile for even longer than 4 minutes to try to get more insight into recalcStyle since there's not too many samples in here.
Running Time Self Symbol Name
2256.0ms 100.0% 10.0 blink::Document::updateRenderTree(blink::StyleRecalcChange)
2236.0ms 99.1% 32.0 blink::Document::updateStyle(blink::StyleRecalcChange)
1977.0ms 87.6% 24.0 blink::Element::recalcOwnStyle(blink::StyleRecalcChange)
1632.0ms 72.3% 7.0 blink::Element::styleForRenderer()
1546.0ms 68.5% 20.0 blink::StyleResolver::styleForElement(blink::Element*, blink::RenderStyle*, blink::StyleSharingBehavior, blink::RuleMatchingBehavior)
600.0ms 26.5% 9.0 blink::StyleResolver::matchAllRules(blink::StyleResolverState&, blink::ElementRuleCollector&, bool)
457.0ms 20.2% 3.0 blink::StyleResolver::matchAuthorRules(blink::Element*, blink::ElementRuleCollector&, bool)
400.0ms 17.7% 48.0 blink::ScopedStyleResolver::collectMatchingAuthorRules(blink::ElementRuleCollector&, bool, bool, unsigned int, unsigned int)
350.0ms 15.5% 150.0 blink::ElementRuleCollector::collectMatchingRules(blink::MatchRequest const&, blink::RuleRange&, blink::SelectorChecker::ContextFlags, unsigned int, unsigned int)
175.0ms 7.7% 70.0 blink::ElementRuleCollector::collectRuleIfMatches(blink::RuleData const&, blink::SelectorChecker::ContextFlags, unsigned int, unsigned int, blink::MatchRequest const&, blink::RuleRange&)
93.0ms 4.1% 11.0 blink::SelectorChecker::Match blink::SelectorChecker::match<blink::DOMSiblingTraversalStrategy>(blink::SelectorChecker::SelectorCheckingContext const&, blink::DOMSiblingTraversalStrategy const&, blink::SelectorChecker::MatchResult*) const
...
52.0ms 2.3% 11.0 blink::ElementRuleCollector::sortAndTransferMatchedRules()
...
120.0ms 5.3% 4.0 blink::StyleResolver::matchUARules(blink::ElementRuleCollector&)
100.0ms 4.4% 2.0 blink::StyleResolver::matchUARules(blink::ElementRuleCollector&, blink::RuleSet*)
81.0ms 3.5% 16.0 blink::ElementRuleCollector::collectMatchingRules(blink::MatchRequest const&, blink::RuleRange&, blink::SelectorChecker::ContextFlags, unsigned int, unsigned int)
55.0ms 2.4% 10.0 blink::ElementRuleCollector::collectRuleIfMatches(blink::RuleData const&, blink::SelectorChecker::ContextFlags, unsigned int, unsigned int, blink::MatchRequest const&, blink::RuleRange&)
37.0ms 1.6% 6.0 blink::SelectorChecker::Match blink::SelectorChecker::match<blink::DOMSiblingTraversalStrategy>(blink::SelectorChecker::SelectorCheckingContext const&, blink::DOMSiblingTraversalStrategy const&, blink::SelectorChecker::MatchResult*) const
...
504.0ms 22.3% 29.0 blink::StyleResolver::applyMatchedProperties(blink::StyleResolverState&, blink::MatchResult const&)
301.0ms 13.3% 17.0 void blink::StyleResolver::applyMatchedProperties<(blink::StyleResolver::StyleApplicationPass)1>(blink::StyleResolverState&, blink::MatchResult const&, bool, int, int, bool)
282.0ms 12.5% 37.0 void blink::StyleResolver::applyProperties<(blink::StyleResolver::StyleApplicationPass)1>(blink::StyleResolverState&, blink::StylePropertySet const*, blink::StyleRule*, bool, bool, blink::PropertyWhitelistType)
95.0ms 4.2% 5.0 void blink::StyleResolver::applyMatchedProperties<(blink::StyleResolver::StyleApplicationPass)0>(blink::StyleResolverState&, blink::MatchResult const&, bool, int, int, bool)
89.0ms 3.9% 38.0 void blink::StyleResolver::applyProperties<(blink::StyleResolver::StyleApplicationPass)0>(blink::StyleResolverState&, blink::StylePropertySet const*, blink::StyleRule*, bool, bool, blink::PropertyWhitelistType)
51.0ms 2.2% 3.0 blink::StyleBuilder::applyProperty(blink::CSSPropertyID, blink::StyleResolverState&, blink::CSSValue*)
46.0ms 2.0% 9.0 blink::StyleBuilder::applyProperty(blink::CSSPropertyID, blink::StyleResolverState&, blink::CSSValue*, bool, bool)
...
135.0ms 5.9% 5.0 blink::StyleResolver::applyAnimatedProperties(blink::StyleResolverState&, blink::Element*)
114.0ms 5.0% 4.0 blink::CSSAnimations::calculateUpdate(blink::Element*, blink::Element const&, blink::RenderStyle const&, blink::RenderStyle*, blink::StyleResolver*)
...
70.0ms 3.1% 2.0 blink::StyleResolverState::StyleResolverState(blink::Document&, blink::Element*, blink::RenderStyle*)
57.0ms 2.5% 7.0 blink::ElementResolveContext::ElementResolveContext(blink::Element&)
45.0ms 1.9% 1.0 blink::VisitedLinkState::determineLinkStateSlowCase(blink::Element const&)
44.0ms 1.9% 2.0 blink::visitedLinkHash(blink::KURL const&, WTF::AtomicString const&)
33.0ms 1.4% 2.0 url::ResolveRelative(char const*, int, url::Parsed const&, char const*, int, url::CharsetConverter*, url::CanonOutputT<char>*, url::Parsed*)
44.0ms 1.9% 7.0 blink::SharedStyleFinder::findSharedStyle()
37.0ms 1.6% 15.0 blink::StyleAdjuster::adjustRenderStyle(blink::RenderStyle*, blink::RenderStyle*, blink::Element*, blink::CachedUAStyle const*)
33.0ms 1.4% 0.0 <Unknown Address>
32.0ms 1.4% 2.0 blink::StyleResolverParentScope::pushParentIfNeeded()
...
66.0ms 2.9% 15.0 blink::CSSAnimations::maybeApplyPendingUpdate(blink::Element*)
...
217.0ms 9.6% 4.0 blink::RenderObject::setStyle(WTF::PassRefPtr<blink::RenderStyle>)
113.0ms 5.0% 1.0 blink::RenderListItem::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
112.0ms 4.9% 0.0 blink::RenderBlockFlow::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
106.0ms 4.6% 3.0 blink::RenderBlock::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
92.0ms 4.0% 0.0 blink::RenderBox::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
86.0ms 3.8% 4.0 blink::RenderLayerModelObject::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
57.0ms 2.5% 2.0 blink::RenderLayer::styleChanged(blink::StyleDifference, blink::RenderStyle const*)
27.0ms 1.1% 3.0 blink::RenderLayerScrollableArea::updateAfterStyleChange(blink::RenderStyle const*)
... lots of little stuff in RenderLayer::styleChanged
40.0ms 1.7% 0.0 blink::RenderStyle::visualInvalidationDiff(blink::RenderStyle const&) const
35.0ms 1.5% 0.0 blink::RenderBlockFlow::styleDidChange(blink::StyleDifference, blink::RenderStyle const*)
21.0ms 0.9% 1.0 blink::RenderBlockFlow::styleWillChange(blink::StyleDifference, blink::RenderStyle const&)
40.0ms 1.7% 9.0 blink::RenderStyle::stylePropagationDiff(blink::RenderStyle const*, blink::RenderStyle const*)
37.0ms 1.6% 11.0 blink::RenderStyle::~RenderStyle()
67.0ms 2.9% 2.0 blink::Text::recalcTextStyle(blink::StyleRecalcChange, blink::Text*)
64.0ms 2.8% 7.0 blink::Element::updatePseudoElement(blink::PseudoId, blink::StyleRecalcChange)
41.0ms 1.8% 15.0 blink::Element::supportsStyleSharing() const
layout also breaks down into mostly the usual things, again scrollbar updating is crazy expensive on OS X. Core layout tasks seem to be 60% of the time, of which 32.4% is under RenderBlockFlow::insertFloatingObject (doing layout on things) and 9.8% is under layoutPositionedObject (doing layout of things). I wonder if we can do those less or make them cheaper? 15.2% is under FrameView::adjustViewSize, specifically 12.4% is inside ScrollView::updateScrollbars. 14% is inside RenderLayer::updateLayerPositionsAfterLayout. Note also that 5.6% of the time is inside ChromeClientImpl::layoutUpdated which is suspicious.
Running Time Self Symbol Name
5707.0ms 100.0% 14.0 blink::FrameView::layout(bool)
3452.0ms 60.4% 6.0 blink::FrameView::performLayout(blink::RenderObject*, bool)
3429.0ms 60.0% 98.0 blink::RenderView::layout()
1854.0ms 32.4% 71.0 blink::RenderBlockFlow::insertFloatingObject(blink::RenderBox*)
634.0ms 11.1% 68.0 blink::RenderListItem::layout()
145.0ms 2.5% 5.0 blink::RenderBlockFlow::updateLogicalWidthAndColumnWidth()
45.0ms 0.7% 1.0 blink::RenderBlockFlow::computeOverflow(blink::LayoutUnit, bool)
40.0ms 0.7% 19.0 blink::RenderBox::computeAndSetBlockDirectionMargins(blink::RenderBlock const*)
40.0ms 0.7% 0.0 blink::RenderBlock::updateBlockChildDirtyBitsBeforeLayout(bool, blink::RenderBox*)
...
271.0ms 4.7% 16.0 blink::RenderBlockFlow::updateLogicalWidthAndColumnWidth()
253.0ms 4.4% 2.0 blink::RenderBlock::updateLogicalWidthAndColumnWidth()
169.0ms 2.9% 7.0 blink::RenderBox::updateLogicalWidth()
160.0ms 2.8% 31.0 blink::RenderBox::computeLogicalWidth(blink::RenderBox::LogicalExtentComputedValues&) const
68.0ms 1.1% 10.0 blink::RenderBox::computeLogicalWidthUsing(blink::SizeType, blink::Length const&, blink::LayoutUnit, blink::RenderBlock const*) const
...
260.0ms 4.5% 9.0 blink::RenderBlock::layoutPositionedObjects(bool, blink::RenderBlock::PositionedLayoutBehavior)
120.0ms 2.1% 4.0 blink::RenderBlockFlow::layoutRunsAndFloatsInRange(blink::LineLayoutState&, blink::BidiResolver<blink::InlineIterator, blink::BidiRun>&, blink::BidiRunList<blink::BidiRun>&, blink::InlineIterator const&, blink::BidiStatus const&)
59.0ms 1.0% 1.0 blink::LineBreaker::nextLineBreak(blink::BidiResolver<blink::InlineIterator, blink::BidiRun>&, blink::BidiRunList<blink::BidiRun>&, blink::LineInfo&, blink::RenderTextInfo&, blink::FloatingObject*, WTF::Vector<blink::WordMeasurement, 64ul, WTF::DefaultAllocator>&)
36.0ms 0.6% 0.0 blink::RenderBlockFlow::createLineBoxesFromBidiRuns(unsigned int, blink::BidiRunList<blink::BidiRun>&, blink::InlineIterator const&, blink::LineInfo&, blink::VerticalPositionCache&, blink::BidiRun*, WTF::Vector<blink::WordMeasurement, 64ul, WTF::DefaultAllocator>&)
...
70.0ms 1.2% 0.0 blink::RenderBlockFlow::computeOverflow(blink::LayoutUnit, bool)
64.0ms 1.1% 20.0 blink::RenderBox::computeAndSetBlockDirectionMargins(blink::RenderBlock const*)
...
304.0ms 5.3% 15.0 blink::RenderBlock::layoutPositionedObjects(bool, blink::RenderBlock::PositionedLayoutBehavior)
230.0ms 4.0% 2.0 blink::RenderBlockFlow::layoutRunsAndFloatsInRange(blink::LineLayoutState&, blink::BidiResolver<blink::InlineIterator, blink::BidiRun>&, blink::BidiRunList<blink::BidiRun>&, blink::InlineIterator const&, blink::BidiStatus const&)
131.0ms 2.2% 0.0 blink::LineBreaker::nextLineBreak(blink::BidiResolver<blink::InlineIterator, blink::BidiRun>&, blink::BidiRunList<blink::BidiRun>&, blink::LineInfo&, blink::RenderTextInfo&, blink::FloatingObject*, WTF::Vector<blink::WordMeasurement, 64ul, WTF::DefaultAllocator>&)
...
199.0ms 3.4% 5.0 blink::RenderBlockFlow::updateLogicalWidthAndColumnWidth()
192.0ms 3.3% 4.0 blink::RenderBlock::updateLogicalWidthAndColumnWidth()
136.0ms 2.3% 6.0 blink::RenderBox::updateLogicalWidth()
122.0ms 2.1% 26.0 blink::RenderBox::computeLogicalWidth(blink::RenderBox::LogicalExtentComputedValues&) const
66.0ms 1.1% 6.0 blink::RenderBox::computeLogicalWidthUsing(blink::SizeType, blink::Length const&, blink::LayoutUnit, blink::RenderBlock const*) const
...
135.0ms 2.3% 7.0 blink::RenderBlockFlow::adjustFloatingBlock(blink::MarginInfo const&)
118.0ms 2.0% 0.0 blink::RenderBlockFlow::computeOverflow(blink::LayoutUnit, bool)
74.0ms 1.2% 5.0 blink::RenderBlockFlow::determineLogicalLeftPositionForChild(blink::RenderBox*)
73.0ms 1.2% 36.0 blink::RenderBlockFlow::collapseMargins(blink::RenderBox*, blink::MarginInfo&, bool)
61.0ms 1.0% 13.0 blink::RenderBlockFlow::rebuildFloatsFromIntruding()
59.0ms 1.0% 2.0 blink::RenderBox::updateLogicalHeight()
...
872.0ms 15.2% 0.0 blink::FrameView::adjustViewSize()
836.0ms 14.6% 4.0 blink::FrameView::setContentsSize(blink::IntSize const&)
733.0ms 12.8% 0.0 blink::ScrollView::setContentsSize(blink::IntSize const&)
713.0ms 12.4% 5.0 blink::ScrollView::updateScrollbars(blink::IntSize const&)
...
58.0ms 1.0% 6.0 blink::ScrollableArea::contentsResized()
...
802.0ms 14.0% 0.0 blink::RenderLayer::updateLayerPositionsAfterLayout(blink::RenderLayer const*, unsigned int)
616.0ms 10.7% 150.0 blink::RenderLayer::updateLayerPositionRecursive(unsigned int)
186.0ms 3.2% 69.0 blink::RenderLayerClipper::clearClipRectsIncludingDescendants()
325.0ms 5.6% 0.0 blink::ChromeClientImpl::layoutUpdated(blink::LocalFrame*) const
161.0ms 2.8% 3.0 blink::FrameView::scheduleOrPerformPostLayoutTasks()
If we look at what is under ChromeClientImpl::layoutUpdated we find that base::Timer is extremely expensive. This code is specific to OS X and the RenderViewImpl::CheckPreferredSize which is for the green bubble resizer. We should consider a different implementation that doesn't force us to start this timer so often and also doesn't make us compute the preferred size of every render object after each layout.
Running Time Self Symbol Name
325.0ms 5.6% 0.0 blink::ChromeClientImpl::layoutUpdated(blink::LocalFrame*) const
324.0ms 5.6% 3.0 blink::WebViewImpl::layoutUpdated(blink::WebLocalFrameImpl*)
268.0ms 4.6% 3.0 non-virtual thunk to content::RenderViewImpl::didUpdateLayout()
249.0ms 4.3% 17.0 content::RenderViewImpl::didUpdateLayout()
178.0ms 3.1% 1.0 base::BaseTimerMethodPointer<content::RenderViewImpl, false>::Start(tracked_objects::Location const&, base::TimeDelta, content::RenderViewImpl*, void (content::RenderViewImpl::*)())
169.0ms 2.9% 8.0 base::Timer::Reset()
160.0ms 2.8% 4.0 base::Timer::PostNewScheduledTask(base::TimeDelta)
140.0ms 2.4% 3.0 base::TaskRunner::PostTask(tracked_objects::Location const&, base::Callback<void ()> const&)
137.0ms 2.4% 1.0 base::internal::MessageLoopProxyImpl::PostDelayedTask(tracked_objects::Location const&, base::Callback<void ()> const&, base::TimeDelta)
133.0ms 2.3% 3.0 base::internal::IncomingTaskQueue::AddToIncomingQueue(tracked_objects::Location const&, base::Callback<void ()> const&, base::TimeDelta, bool)
101.0ms 1.7% 1.0 base::internal::IncomingTaskQueue::PostPendingTask(base::PendingTask*)
96.0ms 1.6% 0.0 base::MessageLoop::ScheduleWork(bool)
91.0ms 1.5% 91.0 base::MessagePumpCFRunLoopBase::ScheduleWork()
----
Impl thread break down shows that most time is rastering text (38%), drawing and clipping rounded rects (21.2%), drawing regular rects (10.8%) and context flushes (12.6%).
Running Time Self Symbol Name
14121.0ms 100.0% 48.0 base::internal::Invoker<1, base::internal::BindState<base::internal::RunnableAdapter<void (cc::GpuRasterWorkerPool::*)()>, void (cc::GpuRasterWorkerPool*), void (base::WeakPtr<cc::GpuRasterWorkerPool>)>, void (cc::GpuRasterWorkerPool*)>::Run(base::internal::BindStateBase*)
11756.0ms 83.2% 6.0 cc::PicturePileImpl::RasterCommon(SkCanvas*, SkDrawPictureCallback*, gfx::Rect const&, float, cc::RenderingStatsInstrumentation*, bool)
11671.0ms 82.6% 3.0 cc::Picture::Raster(SkCanvas*, SkDrawPictureCallback*, cc::Region const&, float)
11650.0ms 82.5% 1.0 SkPicture::draw(SkCanvas*, SkDrawPictureCallback*) const
11642.0ms 82.4% 79.0 SkPicturePlayback::draw(SkCanvas*, SkDrawPictureCallback*)
10953.0ms 77.5% 153.0 SkPicturePlayback::handleOp(SkReader32*, DrawType, unsigned int, SkCanvas*, SkMatrix const&)
5398.0ms 38.2% 52.0 SkCanvas::onDrawPosTextH(void const*, unsigned long, float const*, float, SkPaint const&)
5204.0ms 36.8% 73.0 SkGpuDevice::drawPosText(SkDraw const&, void const*, unsigned long, float const*, float, int, SkPaint const&)
4956.0ms 35.0% 312.0 GrBitmapTextContext::drawPosText(GrPaint const&, SkPaint const&, char const*, unsigned long, float const*, float, int)
1644.0ms 11.6% 783.0 GrBitmapTextContext::drawPackedGlyph(unsigned int, int, int, GrFontScaler*)
1309.0ms 9.2% 65.0 sk_getMetrics_glyph_xy(SkGlyphCache*, char const**, int, int)
808.0ms 5.7% 27.0 GrBitmapTextContext::flushGlyphs()
483.0ms 3.4% 6.0 SkPaint::detachCache(SkDeviceProperties const*, SkMatrix const*, bool) const
183.0ms 1.2% 52.0 GrTextContext::init(GrPaint const&, SkPaint const&)
...
2389.0ms 16.9% 4.0 SkCanvas::clipRRect(SkRRect const&, SkRegion::Op, bool)
899.0ms 6.3% 22.0 SkCanvas::drawRect(SkRect const&, SkPaint const&)
644.0ms 4.5% 7.0 SkCanvas::clipRect(SkRect const&, SkRegion::Op, bool)
620.0ms 4.3% 11.0 SkCanvas::drawRRect(SkRRect const&, SkPaint const&)
402.0ms 2.8% 19.0 SkCanvas::internalDrawBitmapRect(SkBitmap const&, SkRect const*, SkRect const&, SkPaint const*, SkCanvas::DrawBitmapRectFlags)
281.0ms 1.9% 9.0 SkCanvas::drawPath(SkPath const&, SkPaint const&)
...
281.0ms 1.9% 91.0 SkPictureStateTree::Iterator::nextDraw()
270.0ms 1.9% 2.0 SkPictureData::getActiveOps(SkIRect const&) const
...
1785.0ms 12.6% 62.0 GrContext::flush(int)
1515.0ms 10.7% 7.0 GrGpu::onDraw(GrDrawTarget::DrawInfo const&)
632.0ms 4.4% 67.0 GrClipMaskManager::setupClipping(GrClipData const*, GrDrawState::AutoRestoreEffects*, SkRect const*)
546.0ms 3.8% 40.0 GrGpuGL::flushGraphicsState(GrGpu::DrawType, GrDeviceCoordTexture const*)
275.0ms 1.9% 5.0 GrGpuGL::onGpuDraw(GrDrawTarget::DrawInfo const&)
...
161.0ms 1.1% 1.0 SkCanvas::drawColor(unsigned int, SkXfermode::Mode)
...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment