Does this need to be restricted to Googlers only? I see you added rune@ here. :P

I was looking at YouTube recently and it looks like (at least in a profiler) that we're doing a ton of duplicate work resolving variables every time we use them.

Someone on the style team should follow the instructions here:
http://x20web/~esprehn/chrome_profiling.md.html

and figure out where we're spending time.

(FYI: Rune those are just instructions for how to use perf + pprof using https://github.com/google/perf_data_converter)

Yeah, rune@ is fine!

Maybe I misunderstood :P

I asked egarciad@ and he said we can make this public.

Comparing tracing of Document::updateStyle for the two cases shows the same numbers for recalc count, cache hits, shared style hits, etc. This looks like per styleForElement difference.

I've had some issues with ssl-crashes running the test sites through callgrind, but I've got one run with the custom properties one which has 675 calls to styleForElement. According to that callgrind run:

46.32% of styleForElement is spent in 648 (correlates with tracing data which said 27 hits for style sharing) calls to applyMatchedPropertiesAndCustomPropertyAnimations

If I focus on applyMatchedPropertiesAndCustomPropertyAnimations to make that 100%, I get what's in the attached applymatched.png. Notice that valueForCustomProperty is called many times - 27169, 45 times per resolveVariableDefinitions in average.

There is a whole lot of custom properties and custom property references in the custom-properties.html variant. I haven't looked at the details of the variable resolution code, so I don't know what optimizations are in there, but adding or removing --color means we might need to re-resolve other properties, even other custom properties referencing --color.

Deleted: applymatched.png 254 KB

	applymatched.png 254 KB View Download

Custom properties breaks the MPC is some cases, it might be that we have a much smaller hit rate in the custom properties version? In isCacheable:

  if (style.hasVariableReferenceFromNonInheritedProperty())
    return false;

timloh@: right, I must have not read the cache numbers thoroughly enough last time:

Tracing again gives me this for the custom-properties case:

 matchedPropertyCacheHit: 109,
 matchedPropertyCacheInheritedHit: 0,

and the non-custom-properties case alternate between:

 matchedPropertyCacheHit: 211,
 matchedPropertyCacheInheritedHit: 135,

and:

 matchedPropertyCacheHit: 211,
 matchedPropertyCacheInheritedHit: 2,

depending on whether we add or remove the --color property.

Ignore my previous comment about shared style as well, 27 vs 82. I must have compared apples with apples.

Running Linux Chrome 57.0.2970.0 (Official Build) dev (64-bit) on a Z620.

Did an about:tracing comparison using "document.documentElement.lang += 'z'; getComputedStyle(document.documentElement).color;" in the inspector to trigger a warm style recalc (copied from https://cs.chromium.org/chromium/src/tools/perf/measurements/blink_style.py).


Page: https://proj123-2d67f.firebaseapp.com/no-custom-properties.html
Measurement: Document::updateStyle
Wall Duration	13.167 ms
CPU Duration	13.172 ms
resolverAccessCount	455
counters	{
  baseStylesUsed: 0,
  elementsStyled: 453,
  independentInheritedStylesPropagated: 0,
  matchedPropertyApply: 324,
  matchedPropertyCacheAdded: 62,
  matchedPropertyCacheHit: 148,
  matchedPropertyCacheInheritedHit: 49,
  pseudoElementsStyled: 2,
  rulesFastRejected: 13534,
  rulesMatched: 985,
  rulesRejected: 7121,
  sharedStyleCandidates: 247,
  sharedStyleFound: 82,
  sharedStyleLookups: 453,
  sharedStyleRejectedByParent: 0,
  sharedStyleRejectedBySiblingRules: 0,
  sharedStyleRejectedByUncommonAttributeRules: 0,
  stylesAnimated: 4,
  stylesChanged: 453,
  stylesUnchanged: 0,
}


Page: https://proj123-2d67f.firebaseapp.com/custom-properties.html
Measurement: Document:updateStyle
Wall Duration	20.765 ms (+58%)
CPU Duration	20.765 ms (+58%)
resolverAccessCount	455 (+0%)
counters	{
  baseStylesUsed: 0, (+0%)
  elementsStyled: 453, (+0%)
  independentInheritedStylesPropagated: 0, (+0%)
  matchedPropertyApply: 419, (+29%)
  matchedPropertyCacheAdded: 35, (-43%)
  matchedPropertyCacheHit: 76, (-48%)
  matchedPropertyCacheInheritedHit: 9, (-81%)
  pseudoElementsStyled: 2, (+0%)
  rulesFastRejected: 15319, (+13%)
  rulesMatched: 1159, (+17%)
  rulesRejected: 10444, (+46%)
  sharedStyleCandidates: 300, (+21%)
  sharedStyleFound: 27, (-67%)
  sharedStyleLookups: 453, (+0%)
  sharedStyleRejectedByParent: 0, (+0%)
  sharedStyleRejectedBySiblingRules: 0, (+0%)
  sharedStyleRejectedByUncommonAttributeRules: 0, (+0%)
  stylesAnimated: 3, (-25%)
  stylesChanged: 453, (+0%)
  stylesUnchanged: 0, (+0%)
}

Missing the MatchedPropertiesCache will definitely make you slower, so does style sharing, but not by the amount we see here. Looking at the profile it also looks like we're transforming the token stream for the variable declaration into a value on every reacalc instead of caching that transformation. How do we fix that?

This is not exactly a fair comparison.

In the "custom properties" example, there's a style rule (contributed by desktop_polymer.cp.html) that applies to a whole bunch of elements - the selector is "*:not([style-scope]):not(.style-scope)". This selector applies 38 custom properties, and not at the root of the document. The style rule is not present in the "no custom properties" example.

So you're comparing a recalculation which never has to consider any custom properties with one that has to copy (conservatively) 40 properties right down the tree. It's utterly unsurprising that the latter is significantly slower.

I'll look into esprehn@'s suggestion of caching the transformed value but I wouldn't expect we're ever going to get close to performance parity in these two cases.

Closing this bug as the information in the original bug is not up to date as per #15. Please file a new bug if you still see this issue.